Re: [PATCH] Fix data loss in cdc-acm

Re: [PATCH] Fix data loss in cdc-acm

[Johan Hovold]

[ +CC: Alan, Oliver, Peter, Toby, linux-serial, linux-usb ]

On Sun, Jul 19, 2015 at 11:37:07PM +0200, Sven Brauch wrote:
> Since acm_process_read_urb does not check the return value
> of tty_insert_flip_string, it can happen that not all data
> is copied from the urb to the tty if the tty buffer
> is full and throttling does not set in quickly enough. This
> problem is very evident for devices with high data throughput;
> for a device with ~12 MB/s of data transfer, I get a few
> missing kB of data every few MB transferred randomly.

What kernel version are you using?

> To solve this problem, a check is introduced which verifies
> that indeed all data was copied from the urb to the tty buffer.
> If that is not the case, the urb is held in a queue instead
> of resubmitting it to the USB subsystem right away. When new
> data arrives or the tty is unthrottled, the queue is emptied
> again (as far as possible).
> 
> Effectively, this change will force the transmitting USB device
> to wait until the tty buffer can accept new data again, instead
> of discarding the data in this case.

The idea of adding another layer of buffering in the cdc-acm driver has
been suggested in the past but was rejected (or at least questioned).
See for example this thread:

	https://lkml.kernel.org/r/20110608164626.22bc893c@lxorguk.ukuu.org.uk

The tty buffers are quite large these days, but could possibly be bumped
further if needed to give the ldisc some more time to throttle the
device at very high speeds.

Johan

Re: [PATCH] Fix data loss in cdc-acm

[Sven Brauch]

[-- Attachment #1: Type: text/plain, Size: 2379 bytes --]

On 20/07/15 19:25, Johan Hovold wrote:
> What kernel version are you using?
I'm using linux 4.1.2.

> The idea of adding another layer of buffering in the cdc-acm driver has
> been suggested in the past but was rejected (or at least questioned).
> See for example this thread:
> 
> 	https://lkml.kernel.org/r/20110608164626.22bc893c@lxorguk.ukuu.org.uk
Yes, that is indeed pretty much the same problem and the same solution.
Answering to the questions brought up in that thread:

> a) Why is your setup filling 64K in the time it takes the throttle
> response to occur
As far as I understand, the throttle happens only when there's less than
128 bytes of free space in the tty buffer. Data can already be lost
before the tty even decides it should start throttling, simply because
the throttle threshold is smaller than the amount of data potentially in
each urb. Also (excuse my cluelessness) it seems that when exactly the
throttling happens depends on some scheduling "jitter" as well.
Additionally, the response of the cdc_acm driver to a throttle request
is not very prompt; it might have a queue of up to 16kB (16 urbs) pending.

> b) Do we care (is the right thing to do to lose bits anyway at
> that point)
This I cannot answer, I don't know enough about the architecture or
standards. I can just say that for my case, there's a lot of losses;
this it not an issue which happens after hours when the system is under
heavy load, it happens after just a few seconds reproducably.

> The tty buffers are quite large these days, but could possibly be bumped
> further if needed to give the ldisc some more time to throttle the
> device at very high speeds.
I do not like this solution. It will again be based on luck, and you
will still be unable to rely on the delivery guarantee made by the USB
stack (at least when using bulk).
My suggestion instead stops the host system from accepting any more data
from the device when its buffers are full, forcing the device to wait
before sending out more data (which many kinds of devices might very
well be able to do).

Also note that this patch does not introduce an extra layer of
buffering. The buffers are already there; this change just alters the
process which decides when to submit the buffers to the tty, and when to
free them for more input data from the device.

Sven



[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH] Fix data loss in cdc-acm

[Johan Hovold]

On Mon, Jul 20, 2015 at 08:07:33PM +0200, Sven Brauch wrote:
> On 20/07/15 19:25, Johan Hovold wrote:

> > The idea of adding another layer of buffering in the cdc-acm driver has
> > been suggested in the past but was rejected (or at least questioned).
> > See for example this thread:
> > 
> > 	https://lkml.kernel.org/r/20110608164626.22bc893c@lxorguk.ukuu.org.uk
> Yes, that is indeed pretty much the same problem and the same solution.
> Answering to the questions brought up in that thread:
> 
> > a) Why is your setup filling 64K in the time it takes the throttle
> > response to occur
> As far as I understand, the throttle happens only when there's less than
> 128 bytes of free space in the tty buffer. Data can already be lost
> before the tty even decides it should start throttling, simply because
> the throttle threshold is smaller than the amount of data potentially in
> each urb. Also (excuse my cluelessness) it seems that when exactly the
> throttling happens depends on some scheduling "jitter" as well.
> Additionally, the response of the cdc_acm driver to a throttle request
> is not very prompt; it might have a queue of up to 16kB (16 urbs) pending.

Not really. The n_tty ldisc throttles when *its* buffer space is low,
but there should still be plenty of room in the tty buffers.

Looks like the ldisc processing is being starved.

> > b) Do we care (is the right thing to do to lose bits anyway at
> > that point)
> This I cannot answer, I don't know enough about the architecture or
> standards. I can just say that for my case, there's a lot of losses;
> this it not an issue which happens after hours when the system is under
> heavy load, it happens after just a few seconds reproducably.

In general if data isn't being consumed fast enough we eventually need
to drop it (unless we can throttle the producer).

But this isn't necessarily the case in your setup.

> > The tty buffers are quite large these days, but could possibly be bumped
> > further if needed to give the ldisc some more time to throttle the
> > device at very high speeds.
> I do not like this solution. It will again be based on luck, and you
> will still be unable to rely on the delivery guarantee made by the USB
> stack (at least when using bulk).

See above.

> My suggestion instead stops the host system from accepting any more data
> from the device when its buffers are full, forcing the device to wait
> before sending out more data (which many kinds of devices might very
> well be able to do).

This is what we are supposed to do today, but by relying on the ldisc
and tty buffers rather than forcing every driver to implement another
custom throttling mechanism.

But something obviously isn't working as intended.

Johan

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

Hi Sven,

On 07/21/2015 05:18 AM, Johan Hovold wrote:
> On Mon, Jul 20, 2015 at 08:07:33PM +0200, Sven Brauch wrote:
>> On 20/07/15 19:25, Johan Hovold wrote:
> 
>>> The idea of adding another layer of buffering in the cdc-acm driver has
>>> been suggested in the past but was rejected (or at least questioned).
>>> See for example this thread:
>>>
>>> 	https://lkml.kernel.org/r/20110608164626.22bc893c-qBU/x9rampVanCEyBjwyrvXRex20P6io@public.gmane.org
>> Yes, that is indeed pretty much the same problem and the same solution.
>> Answering to the questions brought up in that thread:
>>
>>> a) Why is your setup filling 64K in the time it takes the throttle
>>> response to occur
>> As far as I understand, the throttle happens only when there's less than
>> 128 bytes of free space in the tty buffer. Data can already be lost
>> before the tty even decides it should start throttling, simply because
>> the throttle threshold is smaller than the amount of data potentially in
>> each urb. Also (excuse my cluelessness) it seems that when exactly the
>> throttling happens depends on some scheduling "jitter" as well.
>> Additionally, the response of the cdc_acm driver to a throttle request
>> is not very prompt; it might have a queue of up to 16kB (16 urbs) pending.
> 
> Not really. The n_tty ldisc throttles when *its* buffer space is low,
> but there should still be plenty of room in the tty buffers.
> 
> Looks like the ldisc processing is being starved.

Just to expand on Johan's explanation somewhat.

The tty buffers are separate from the fixed 4KB n_tty line discipline
read buffer. The 4KB read buffer holds data which has already been
processed as input based on the current termios settings.

The tty buffers hold unprocessed rx data; because the cdc-acm driver
does not use per-char flags, the default tty buffer limit amounts to
a 128KB buffer, which is roughly 10ms at your line rate of 96Mb/s.

10ms is a long time for a kworker thread (which would indicate throttle)
to not be running once scheduled, so I doubt scheduler latency is
actually the problem.

More likely suspects are:
1. Because most drivers don't properly handle concurrent throttle/unthrottle,
   the n_tty line discipline excludes one while the other is in-progress.
   acm_tty_unthrottle() first clears throttle state, thus letting input
   proceed, and then continues to submit previously in-flight urbs. During this
   time, the driver cannot receive throttle notification (ie., acm_tty_throttle()
   will not be called).

2. The reader/consumer can't process at that line rate, or related, the
   reader/consumer can't catch up once it has fallen behind.

Some interesting experiments would be:
1. Instrument acm_read_bulk_callback with tty_buffer_space_avail() to track
   the (approx) fill level of the tty buffers. I would use ftrace/trace_printk()
   to record this.
2. Similarly instrument acm_tty_throttle/acm_tty_unthrottle.


>>> b) Do we care (is the right thing to do to lose bits anyway at
>>> that point)
>> This I cannot answer, I don't know enough about the architecture or
>> standards. I can just say that for my case, there's a lot of losses;
>> this it not an issue which happens after hours when the system is under
>> heavy load, it happens after just a few seconds reproducably.
> 
> In general if data isn't being consumed fast enough we eventually need
> to drop it (unless we can throttle the producer).
> 
> But this isn't necessarily the case in your setup.
> 
>>> The tty buffers are quite large these days, but could possibly be bumped
>>> further if needed to give the ldisc some more time to throttle the
>>> device at very high speeds.
>> I do not like this solution. It will again be based on luck, and you
>> will still be unable to rely on the delivery guarantee made by the USB
>> stack (at least when using bulk).
> 
> See above.

A driver can set the upper limit of tty buffers on a per-tty basis with
tty_buffer_set_limit(). The default limit is 64KB. This limit must be
set before the tty can receive input.


>> My suggestion instead stops the host system from accepting any more data
>> from the device when its buffers are full, forcing the device to wait
>> before sending out more data (which many kinds of devices might very
>> well be able to do).
> 
> This is what we are supposed to do today, but by relying on the ldisc
> and tty buffers rather than forcing every driver to implement another
> custom throttling mechanism.
> 
> But something obviously isn't working as intended.

Let me know if you need help instrumenting the tty buffers/throttling
to help figure out what the actual problem is.

Regarding the patch itself, I have no opinion on the suitability of
simply not resubmitting urbs. However, that is exactly how the throttle
mechanism works, and the tty buffer API is specifically designed to
allow drivers to manage flow via that interface as well (especially
for high-throughput drivers).

The n_tty throttle/unthrottle is a very indirect method for restricting
flow, and at extremely high bit rates may not be appropriate. (It's
mostly a historical vestige from pre-tty buffer days).

Regards,
Peter Hurley

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Fix data loss in cdc-acm

[Oliver Neukum]

On Tue, 2015-07-21 at 12:45 -0400, Peter Hurley wrote:
> Let me know if you need help instrumenting the tty buffers/throttling
> to help figure out what the actual problem is.
> 
> Regarding the patch itself, I have no opinion on the suitability of
> simply not resubmitting urbs. However, that is exactly how the
> throttle
> mechanism works, and the tty buffer API is specifically designed to
> allow drivers to manage flow via that interface as well (especially
> for high-throughput drivers).

Could you please expand on how this is supposed to work?
For once how does one learn that room is available again?

	Regards
		Oliver

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 07/22/2015 04:40 AM, Oliver Neukum wrote:
> On Tue, 2015-07-21 at 12:45 -0400, Peter Hurley wrote:
>> Let me know if you need help instrumenting the tty buffers/throttling
>> to help figure out what the actual problem is.
>>
>> Regarding the patch itself, I have no opinion on the suitability of
>> simply not resubmitting urbs. However, that is exactly how the
>> throttle
>> mechanism works, and the tty buffer API is specifically designed to
>> allow drivers to manage flow via that interface as well (especially
>> for high-throughput drivers).
> 
> Could you please expand on how this is supposed to work?
> For once how does one learn that room is available again?

There are basically 3 mechanisms for managing rx data:
1. Allocate space when the data arrives; drop data if no space is avail
   and indicate buf_overrun. This is what most drivers do.
2. Allocate space when the data arrives; try to buffer uncopied data
   and resubmit the data later. Some high-throughput drivers (in the wild)
   do this (but less so now that the tty buffer space is configurable).
3. Pre-allocate space _before_ the data arrives (with tty_buffer_request_room());
   this is applicable to subsystems which know how much data can be in-flight
   at any one time. This guarantees that when rx data arrives buffer space is
   available (since it has already been allocated).

Drivers that use method 2 typically attempt to recopy the buffered data
when either new data arrives or @ unthrottle. I've seen others use deferred
work as well.

AFAIK no driver/subsystem is using method 3 for guaranteed delivery
of in-flight data, but it seems ideally suited to usb serial.

Regards,
Peter Hurley

Re: [PATCH] Fix data loss in cdc-acm

[Oliver Neukum]

On Wed, 2015-07-22 at 10:30 -0400, Peter Hurley wrote:
> 3. Pre-allocate space _before_ the data arrives (with
> tty_buffer_request_room());
>    this is applicable to subsystems which know how much data can be
> in-flight
>    at any one time. This guarantees that when rx data arrives buffer
> space is
>    available (since it has already been allocated).
> 
> Drivers that use method 2 typically attempt to recopy the buffered
> data
> when either new data arrives or @ unthrottle. I've seen others use
> deferred
> work as well.
> 
> AFAIK no driver/subsystem is using method 3 for guaranteed delivery
> of in-flight data, but it seems ideally suited to usb serial.

Indeed. But flow control is still done by throttle/unthrottle, isn't it?

	Regards
		Oliver

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 07/22/2015 11:01 AM, Oliver Neukum wrote:
> On Wed, 2015-07-22 at 10:30 -0400, Peter Hurley wrote:
>> 3. Pre-allocate space _before_ the data arrives (with
>> tty_buffer_request_room());
>>    this is applicable to subsystems which know how much data can be
>> in-flight
>>    at any one time. This guarantees that when rx data arrives buffer
>> space is
>>    available (since it has already been allocated).
>>
>> Drivers that use method 2 typically attempt to recopy the buffered
>> data
>> when either new data arrives or @ unthrottle. I've seen others use
>> deferred
>> work as well.
>>
>> AFAIK no driver/subsystem is using method 3 for guaranteed delivery
>> of in-flight data, but it seems ideally suited to usb serial.
> 
> Indeed. But flow control is still done by throttle/unthrottle, isn't it?

Oliver, somehow I never saw this. Please accept my apologies.

Well, input flow control from the driver would be implicitly limited
by a failure to allocate new buffer space after the old buffer was
inserted and pushed. In the case of urbs, this would simply mean that
the urb could not be resubmitted yet, and would have to be deferred.
So preventing buffer overrun wouldn't rely on throttle.

WRT flow control, method 3 only needs to know when to resume.
As with method 2, this could be @ unthrottle or by retry in deferred work
(essentially polling). At least that's what's currently available.

Regardless, tty drivers should still respond to throttle/unthrottle
requests so as to limit input data when there is no active reader.

All that being said, unthrottle behaves degenerately at very high line
rates and throughput, which needs to be resolved.

The central issue is that the wrong thread is evaluating the wrong
conditions for restart. A further complication is that unthrottle
is guaranteed race-free reads of struct termios which limit the contexts
from which unthrottle can be called.

So to recap; the tty buffer api already provides the necessary interface
for preventing buffer overrun and drivers/subsystems with very high line
rates should be utilizing that interface instead of relying on throttle.

In addition, a more reliable/appropriate method of restart is required
(preferably by fixing when/why unthrottle is invoked). I'll look into that.

Regards,
Peter Hurley
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Fix data loss in cdc-acm

[Oliver Neukum]

On Mon, 2015-07-20 at 20:07 +0200, Sven Brauch wrote:
> On 20/07/15 19:25, Johan Hovold wrote:
> > What kernel version are you using?
> I'm using linux 4.1.2.
> 
> > The idea of adding another layer of buffering in the cdc-acm driver has
> > been suggested in the past but was rejected (or at least questioned).
> > See for example this thread:
> > 
> > 	https://lkml.kernel.org/r/20110608164626.22bc893c@lxorguk.ukuu.org.uk
> Yes, that is indeed pretty much the same problem and the same solution.
> Answering to the questions brought up in that thread:

Yes, but that was not really a modem. The stuff on the other end
doesn't come over an external conection.

> > a) Why is your setup filling 64K in the time it takes the throttle
> > response to occur
> As far as I understand, the throttle happens only when there's less than
> 128 bytes of free space in the tty buffer. Data can already be lost
> before the tty even decides it should start throttling, simply because
> the throttle threshold is smaller than the amount of data potentially in
> each urb. Also (excuse my cluelessness) it seems that when exactly the

Then there is a problem in the tty code. Now it may not have enough
information, but there is no point of turning the buffers of cdc-acm
into an inofficial buffer.

> throttling happens depends on some scheduling "jitter" as well.
> Additionally, the response of the cdc_acm driver to a throttle request
> is not very prompt; it might have a queue of up to 16kB (16 urbs) pending.
> 
> > b) Do we care (is the right thing to do to lose bits anyway at
> > that point)
> This I cannot answer, I don't know enough about the architecture or
> standards. I can just say that for my case, there's a lot of losses;
> this it not an issue which happens after hours when the system is under
> heavy load, it happens after just a few seconds reproducably.

Then the tty layer needs to throttle earlier. In the general case we
must be ready to throw away data.

> > The tty buffers are quite large these days, but could possibly be bumped
> > further if needed to give the ldisc some more time to throttle the
> > device at very high speeds.
> I do not like this solution. It will again be based on luck, and you
> will still be unable to rely on the delivery guarantee made by the USB
> stack (at least when using bulk).
> My suggestion instead stops the host system from accepting any more data
> from the device when its buffers are full, forcing the device to wait
> before sending out more data (which many kinds of devices might very
> well be able to do).

But others won't and we'd preserve stale data in preference over fresh
data.

> Also note that this patch does not introduce an extra layer of
> buffering. The buffers are already there; this change just alters the
> process which decides when to submit the buffers to the tty, and when to
> free them for more input data from the device.

It does. It turns those buffers from temporary scratch buffers into
a queue.

	Regards
		Oliver

Re: [PATCH] Fix data loss in cdc-acm

[Sven Brauch]

[-- Attachment #1: Type: text/plain, Size: 2394 bytes --]

Hi,

Thank you for your comments.

On 21/07/15 15:43, Oliver Neukum wrote:
> But others won't and we'd preserve stale data in preference over fresh
> data.
If that is important for your device, you should be using an isochronous
endpoint, not bulk, no?
Also note that the driver currently does this anyways. It loses a few kB
of data, and _then_ it throttles the producer and forces it to wait.

On 21/07/15 11:18, Johan Hovold wrote:
> In general if data isn't being consumed fast enough we eventually need
> to drop it (unless we can throttle the producer).
Yes, maybe this is the first thing which should be cleared up: Is
"throttle the producer" always preferable over "lose data"? I'd say yes
for bulk transfers, no for isochronous. It is in principle easy enough
to throttle the producer, that is what e.g. my patch does. Whether a
different approach may be more appropriate than the "don't resubmit the
urbs" thing is then of course open to debate.

As far as I can see, throttling the producer is the only way to
guarantee data delivery. So if we want that (and I certainly want it for
my application, I don't know about the general case), I think all
changes to the tty buffers or throttling mechanisms are "just"
performance optimization, since no such modification will ever guarantee
delivery if the producer is not throttled in time.
And, this I want to mention again, if your producer is timing-sensitive
you would not be using bulk anyways. The USB controller could just
decide that your device cannot send data for the next five seconds, and
it will have to handle that case as well. Thus I see no reason to not
throttle the producer if necessary.

On 21/07/15 18:45, Peter Hurley wrote:
> 1. Instrument acm_read_bulk_callback with tty_buffer_space_avail()
> to track the (approx) fill level of the tty buffers. I would
> use ftrace/trace_printk() to record this.
I already did this while debugging. For a while, the buffer is almost
empty (fluctuates by a few kB), then it rapidly drops to zero bytes
free. Only after a few urbs where submitted (or rather, not submitted)
into the full buffer, the throttle flag gets set.

Thank you for your offer to help figuring out what exactly goes wrong
with the throttling mechanism. If it turns out we should actually look
for a fix there, I'll be happy to make use of it.

Best,
Sven


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 07/21/2015 05:43 PM, Sven Brauch wrote:
> Hi,
> 
> Thank you for your comments.
> 
> On 21/07/15 15:43, Oliver Neukum wrote:
>> But others won't and we'd preserve stale data in preference over fresh
>> data.
> If that is important for your device, you should be using an isochronous
> endpoint, not bulk, no?
> Also note that the driver currently does this anyways. It loses a few kB
> of data, and _then_ it throttles the producer and forces it to wait.
> 
> On 21/07/15 11:18, Johan Hovold wrote:
>> In general if data isn't being consumed fast enough we eventually need
>> to drop it (unless we can throttle the producer).
> Yes, maybe this is the first thing which should be cleared up: Is
> "throttle the producer" always preferable over "lose data"? I'd say yes
> for bulk transfers, no for isochronous. It is in principle easy enough
> to throttle the producer, that is what e.g. my patch does. Whether a
> different approach may be more appropriate than the "don't resubmit the
> urbs" thing is then of course open to debate.
> 
> As far as I can see, throttling the producer is the only way to
> guarantee data delivery. So if we want that (and I certainly want it for
> my application, I don't know about the general case), I think all
> changes to the tty buffers or throttling mechanisms are "just"
> performance optimization, since no such modification will ever guarantee
> delivery if the producer is not throttled in time.
> And, this I want to mention again, if your producer is timing-sensitive
> you would not be using bulk anyways. The USB controller could just
> decide that your device cannot send data for the next five seconds, and
> it will have to handle that case as well. Thus I see no reason to not
> throttle the producer if necessary.

It's unclear to me that you haven't hit some other bug (buffer miscalc,
failure to progress, etc.) which is affecting other users but just not
to the extent you're experiencing.

For example, I made changes to the conditions required to restart the
input worker; I may have omitted some necessary condition which you've
triggered.


> On 21/07/15 18:45, Peter Hurley wrote:
>> 1. Instrument acm_read_bulk_callback with tty_buffer_space_avail()
>> to track the (approx) fill level of the tty buffers. I would
>> use ftrace/trace_printk() to record this.
> I already did this while debugging. For a while, the buffer is almost
> empty (fluctuates by a few kB), then it rapidly drops to zero bytes
> free. Only after a few urbs where submitted (or rather, not submitted)
> into the full buffer, the throttle flag gets set.

I'd like to see that data, if you can, which will help me understand
at least the timing.

Regards,
Peter Hurley

Re: [PATCH] Fix data loss in cdc-acm

[Sven Brauch]

[-- Attachment #1: Type: text/plain, Size: 32442 bytes --]

Hey,

On 22/07/15 01:34, Peter Hurley wrote:
> I'd like to see that data, if you can, which will help me understand
> at least the timing.
Sure, please see below for the code which produced the output
and the actual output. Let me know if you need anything else.
This was run with the unmodified version of the driver, i.e. without
my patch.

Sven
------

Code which produced the output:

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index 5c8f581..3d26c87 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -404,12 +404,16 @@ static int acm_submit_read_urbs(struct acm *acm, gfp_t mem_flags)
 
 static void acm_process_read_urb(struct acm *acm, struct urb *urb)
 {
+    int written;
+
        if (!urb->actual_length)
                return;
 
-       tty_insert_flip_string(&acm->port, urb->transfer_buffer,
+       written = tty_insert_flip_string(&acm->port, urb->transfer_buffer,
                        urb->actual_length);
        tty_flip_buffer_push(&acm->port);
+    printk("cdc-acm: acm_process_read_urb: processed %d of %d (free space left: %d)\n",
+           written, urb->actual_length, tty_buffer_space_avail(&acm->port));
 }
 
 static void acm_read_bulk_callback(struct urb *urb)
@@ -448,6 +452,9 @@ static void acm_read_bulk_callback(struct urb *urb)
        /* throttle device if requested by tty */
        spin_lock_irqsave(&acm->read_lock, flags);
        acm->throttled = acm->throttle_req;
+    if (acm->throttle_req) {
+        printk("cdc-acm: acm_read_bulk_callback: throttle requested\n");
+    }
        if (!acm->throttled) {
                spin_unlock_irqrestore(&acm->read_lock, flags);
                acm_submit_read_urb(acm, rb->index, GFP_ATOMIC);
@@ -758,6 +765,9 @@ static void acm_tty_throttle(struct tty_struct *tty)
 {
        struct acm *acm = tty->driver_data;
 
+    printk("cdc-acm: acm_tty_throttle: called; free space in tty: %d\n",
+           tty_buffer_space_avail(&acm->port));
+
        spin_lock_irq(&acm->read_lock);
        acm->throttle_req = 1;
        spin_unlock_irq(&acm->read_lock);
@@ -768,6 +778,9 @@ static void acm_tty_unthrottle(struct tty_struct *tty)
        struct acm *acm = tty->driver_data;
        unsigned int was_throttled;
 
+    printk("cdc-acm: acm_tty_unthrottle: called; free space in tty: %d\n",
+           tty_buffer_space_avail(&acm->port));
+
        spin_lock_irq(&acm->read_lock);
        was_throttled = acm->throttled;
        acm->throttled = 0;

______________________________
Output from dmesg (cut a bit in the beginning):

[...]
[62517.602478] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.602480] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.602483] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.602485] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.602487] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.602489] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.602494] cdc-acm: acm_tty_throttle: called; free space in tty: 63488
[62517.602600] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.602602] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602603] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.602604] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602606] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.602607] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602609] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.602610] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602612] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60416)
[62517.602613] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602726] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.602727] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602729] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.602730] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602731] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.602732] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602734] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.602735] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602737] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.602738] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.602959] cdc-acm: acm_tty_unthrottle: called; free space in tty: 64512
[62517.603852] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 64256)
[62517.603856] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.603858] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.603976] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.603979] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.603981] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.603983] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.603985] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.603991] cdc-acm: acm_tty_throttle: called; free space in tty: 63488
[62517.604101] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 64512)
[62517.604103] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604105] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.604105] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604107] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.604108] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604110] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.604111] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604113] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.604115] cdc-acm: acm_tty_unthrottle: called; free space in tty: 62464
[62517.604121] cdc-acm: acm_tty_throttle: called; free space in tty: 64512
[62517.604227] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.604228] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604230] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.604231] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604233] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.604234] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604235] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.604236] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.604375] cdc-acm: acm_tty_unthrottle: called; free space in tty: 64512
[62517.605355] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 64256)
[62517.605358] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.605360] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.605362] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.605364] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.605371] cdc-acm: acm_tty_throttle: called; free space in tty: 64512
[62517.605478] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.605479] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605481] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.605482] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605484] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605485] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605487] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605488] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605490] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.605491] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605602] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.605603] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605605] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605606] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605608] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605609] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605610] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.605611] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605613] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.605614] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605726] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605728] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605729] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.605730] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.605891] cdc-acm: acm_tty_unthrottle: called; free space in tty: 64512
[62517.606858] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 64256)
[62517.606862] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.606864] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.606866] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.606868] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.606871] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.606873] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.606881] cdc-acm: acm_tty_throttle: called; free space in tty: 63488
[62517.606978] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.606980] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.606982] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.606983] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.606985] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.606986] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.606987] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.606988] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.606990] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60416)
[62517.606991] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607102] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.607104] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607106] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.607107] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607108] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.607109] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607111] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60416)
[62517.607112] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607114] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60416)
[62517.607115] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.607414] cdc-acm: acm_tty_unthrottle: called; free space in tty: 64512
[62517.608229] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 64256)
[62517.608232] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.608234] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.608236] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.608353] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 64512)
[62517.608356] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608358] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608361] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.608363] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.608401] cdc-acm: acm_tty_throttle: called; free space in tty: 64512
[62517.608480] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608481] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608483] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608484] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608485] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.608486] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608488] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62464)
[62517.608489] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608491] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61440)
[62517.608492] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608603] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 64512)
[62517.608604] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608606] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608607] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608609] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63488)
[62517.608610] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.608691] cdc-acm: acm_tty_unthrottle: called; free space in tty: 64512
[62517.609738] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 64256)
[62517.609743] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.609747] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 63232)
[62517.609750] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.609754] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 62208)
[62517.609757] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.609855] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 61184)
[62517.609859] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60160)
[62517.609862] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 60160)
[62517.609866] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 59136)
[62517.610023] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 59136)
[62517.610030] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 58112)
[62517.610035] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 58112)
[62517.610040] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 57088)
[62517.610106] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 57088)
[62517.610110] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 56064)
[62517.610113] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 56064)
[62517.611115] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 55808)
[62517.611119] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 54784)
[62517.611231] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 54784)
[62517.611236] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 53760)
[62517.611240] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 53760)
[62517.611243] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 52736)
[62517.611247] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 52736)
[62517.611386] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 51712)
[62517.611391] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 51712)
[62517.611396] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 50688)
[62517.611401] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 50688)
[62517.611406] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 49664)
[62517.611482] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 49664)
[62517.611489] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 48640)
[62517.611493] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 48640)
[62517.611606] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 47616)
[62517.611609] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 47616)
[62517.612610] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 47360)
[62517.612615] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 46336)
[62517.612618] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 46336)
[62517.612622] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 45312)
[62517.612734] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 45312)
[62517.612738] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 44288)
[62517.612741] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 44288)
[62517.612745] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 43264)
[62517.612859] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 43264)
[62517.612862] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 42240)
[62517.612866] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 42240)
[62517.612869] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 41216)
[62517.612981] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 41216)
[62517.612984] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 40192)
[62517.612987] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 40192)
[62517.612991] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 39168)
[62517.613106] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 39168)
[62517.614111] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 38912)
[62517.614116] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 37888)
[62517.614119] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 37888)
[62517.614124] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 36864)
[62517.614127] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 36864)
[62517.614130] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 35840)
[62517.614232] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 35840)
[62517.614235] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 34816)
[62517.614239] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 34816)
[62517.614247] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 33792)
[62517.614359] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 33792)
[62517.614363] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 32768)
[62517.614366] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 32768)
[62517.614369] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 31744)
[62517.614483] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 31744)
[62517.614486] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 30720)
[62517.614489] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 30720)
[62517.615485] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 30464)
[62517.615489] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 29440)
[62517.615492] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 29440)
[62517.615611] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 28416)
[62517.615614] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 28416)
[62517.615617] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 27392)
[62517.615734] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 27392)
[62517.615737] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 26368)
[62517.615741] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 26368)
[62517.615746] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 25344)
[62517.615749] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 25344)
[62517.615858] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 24320)
[62517.615861] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 24320)
[62517.615864] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 23296)
[62517.615867] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 23296)
[62517.615983] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 22272)
[62517.615986] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 22272)
[62517.616989] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 22016)
[62517.616994] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 20992)
[62517.616997] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 20992)
[62517.617001] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 19968)
[62517.617110] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 19968)
[62517.617114] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 18944)
[62517.617117] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 18944)
[62517.617120] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 17920)
[62517.617233] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 17920)
[62517.617240] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 16896)
[62517.617243] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 16896)
[62517.617246] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 15872)
[62517.617362] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 15872)
[62517.617366] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 14848)
[62517.617369] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 14848)
[62517.617372] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 13824)
[62517.617484] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 13824)
[62517.618487] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 13568)
[62517.618491] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 12544)
[62517.618494] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 12544)
[62517.618498] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 11520)
[62517.618501] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 11520)
[62517.618504] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 10496)
[62517.618507] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 10496)
[62517.618613] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 9472)
[62517.618616] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 9472)
[62517.618621] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 8448)
[62517.618625] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 8448)
[62517.618737] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 7424)
[62517.618740] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 7424)
[62517.618744] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 6400)
[62517.618747] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 6400)
[62517.618859] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 5376)
[62517.618862] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 5376)
[62517.619863] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 5120)
[62517.619867] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 4096)
[62517.619870] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 4096)
[62517.619874] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.620022] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.620028] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.620033] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.620037] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 1024)
[62517.620113] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.620118] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 1024)
[62517.620121] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 1024)
[62517.620126] cdc-acm: acm_tty_throttle: called; free space in tty: 2304
[62517.620245] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2304)
[62517.620247] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620250] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2304)
[62517.620251] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620253] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 1280)
[62517.620255] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620257] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 1280)
[62517.620258] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620264] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 256)
[62517.620265] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620267] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 256)
[62517.620269] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.620318] cdc-acm: acm_tty_unthrottle: called; free space in tty: 256
[62517.621367] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 0)
[62517.621372] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 0)
[62517.621375] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 0)
                  ------- FAILURE HAPPENS HERE --------
[62517.621378] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621381] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621489] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621492] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621495] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621618] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621622] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621626] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621744] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621747] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621750] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621862] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621865] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.621867] cdc-acm: acm_process_read_urb: processed 0 of 1024 (free space left: 0)
[62517.622357] cdc-acm: acm_tty_throttle: called; free space in tty: 1024
[62517.622746] cdc-acm: acm_process_read_urb: processed 16 of 16 (free space left: 6144)
[62517.622748] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622750] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 5120)
[62517.622751] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622753] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 5120)
[62517.622754] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622863] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 4096)
[62517.622864] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622866] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 4096)
[62517.622867] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622869] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.622870] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622872] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.622873] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622875] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.622876] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622989] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 4096)
[62517.622991] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622993] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.622994] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622996] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.622997] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.622999] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.623000] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.623002] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.623003] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.623116] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.623118] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.623119] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 3072)
[62517.623120] cdc-acm: acm_read_bulk_callback: throttle requested
[62517.623122] cdc-acm: acm_process_read_urb: processed 1024 of 1024 (free space left: 2048)
[62517.623123] cdc-acm: acm_read_bulk_callback: throttle requested


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

Hi Sven,

On 07/21/2015 08:47 PM, Sven Brauch wrote:
> On 22/07/15 01:34, Peter Hurley wrote:
>> I'd like to see that data, if you can, which will help me understand
>> at least the timing.
> Sure, please see below for the code which produced the output
> and the actual output. Let me know if you need anything else.
> This was run with the unmodified version of the driver, i.e. without
> my patch.

Thanks for this, which confirms that roughly 10.4ms elapses from
kworker schedule (of input into nearly empty tty buffers) to throttle
notification.

The premature unthrottle actually leads to the data loss but the throttling
with a mere 2K left is _way too late_.

10ms is a _really_ long time for a cpu not to attend to a kworker.
Which raises 2 questions:
1. What are the termios settings of the tty receiving input? Is it 'raw'
   mode or typical terminal mode (icanon, echo, etc.) or something else?
2. Are there RT threads that are hogging cpu time?

Regards,
Peter Hurley

Re: [PATCH] Fix data loss in cdc-acm

[Sven Brauch]

[-- Attachment #1: Type: text/plain, Size: 1057 bytes --]

Hi,

On 23/07/15 00:12, Peter Hurley wrote:
> The premature unthrottle actually leads to the data loss but the throttling
> with a mere 2K left is _way too late_.
Ok, yes, I think so too.

> 10ms is a _really_ long time for a cpu not to attend to a kworker.
> Which raises 2 questions:
> 1. What are the termios settings of the tty receiving input? Is it 'raw'
>    mode or typical terminal mode (icanon, echo, etc.) or something else?
In my test code, I open the tty like
  fd = open("/dev/ttyACM0", O_RDWR | O_NOCTTY | O_NONBLOCK);
I don't make any other changes to the default settings. To be honest,
I'm not sure in which mode it is operating then (I was assuming raw, but
I might be wrong?).

> 2. Are there RT threads that are hogging cpu time?
I can't see any, I think the only thing which occasionally goes to RT is
pulseaudio (but during at least some of the tests I wasn't even playing
audio, so that sounds very unplausible to me). I also cannot see a
correlation between failure rate and CPU load.

Best regards,
Sven


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 819 bytes --]

Re: [PATCH] Fix data loss in cdc-acm

[Peter Stuge]

Sven Brauch wrote:
> I don't make any other changes to the default settings. To be honest,
> I'm not sure in which mode it is operating then (I was assuming raw, but
> I might be wrong?).

You should explicitly set a mode if you need a particular mode,
otherwise the port might be in another mode. This sets raw. Add
error checking.

struct termios t;

tcgetattr(fd, &t);
cfmakeraw(&t);
cfsetspeed(&t, B115200);
tcsetattr(fd, 0, &t);


//Peter

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 07/22/2015 06:53 PM, Sven Brauch wrote:
> Hi,
> 
> On 23/07/15 00:12, Peter Hurley wrote:
>> The premature unthrottle actually leads to the data loss but the throttling
>> with a mere 2K left is _way too late_.
> Ok, yes, I think so too.
> 
>> 10ms is a _really_ long time for a cpu not to attend to a kworker.

I haven't forgotten about this problem and I still plan to look into why
the long delay, particularly focusing on the scheduling latency from
tty_flip_buffer_push() => flush_to_ldisc().

Regards,
Peter Hurley

>> Which raises 2 questions:
>> 1. What are the termios settings of the tty receiving input? Is it 'raw'
>>    mode or typical terminal mode (icanon, echo, etc.) or something else?
> In my test code, I open the tty like
>   fd = open("/dev/ttyACM0", O_RDWR | O_NOCTTY | O_NONBLOCK);
> I don't make any other changes to the default settings. To be honest,
> I'm not sure in which mode it is operating then (I was assuming raw, but
> I might be wrong?).
> 
>> 2. Are there RT threads that are hogging cpu time?
> I can't see any, I think the only thing which occasionally goes to RT is
> pulseaudio (but during at least some of the tests I wasn't even playing
> audio, so that sounds very unplausible to me). I also cannot see a
> correlation between failure rate and CPU load.
> 
> Best regards,
> Sven
> 

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 08/05/2015 01:36 PM, Peter Hurley wrote:
> On 07/22/2015 06:53 PM, Sven Brauch wrote:
>> On 23/07/15 00:12, Peter Hurley wrote:
>>> The premature unthrottle actually leads to the data loss but the throttling
>>> with a mere 2K left is _way too late_.
>> Ok, yes, I think so too.
>>
>>> 10ms is a _really_ long time for a cpu not to attend to a kworker.
> 
> I haven't forgotten about this problem and I still plan to look into why
> the long delay, particularly focusing on the scheduling latency from
> tty_flip_buffer_push() => flush_to_ldisc().

I made some changes wrt which CPU is scheduled for the flush_to_ldisc()
input worker, which should reduce the kworker latency. The changes are
on the tty-next branch of Greg's tty.git tree; please test at your earliest
convenience.


>>> 1. What are the termios settings of the tty receiving input? Is it 'raw'
>>>    mode or typical terminal mode (icanon, echo, etc.) or something else?
>> In my test code, I open the tty like
>>   fd = open("/dev/ttyACM0", O_RDWR | O_NOCTTY | O_NONBLOCK);
>> I don't make any other changes to the default settings. To be honest,
>> I'm not sure in which mode it is operating then (I was assuming raw, but
>> I might be wrong?).

ECHO is on by default and the cdc-acm driver does not implement the
put_char() and flush_chars() tty driver methods, which made the problem
_way worse_, since every echoed char is sent as it's own URB.

Since echoing is performed by the input worker, this seems the likely
cause for the significant delay in ldisc processing.

Echo processing should probably be performed by a separate kworker rather
than by the input kworker.

Regards,
Peter Hurley

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo-u79uwXL29TY76Z2rM5mHXA@public.gmane.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: [PATCH] Fix data loss in cdc-acm

[Oliver Neukum]

On Tue, 2015-10-20 at 14:16 -0400, Peter Hurley wrote:
> ECHO is on by default and the cdc-acm driver does not implement the
> put_char() and flush_chars() tty driver methods, which made the
> problem
> _way worse_, since every echoed char is sent as it's own URB.

That can be fixed. How can I test this? Will the tty layer use write()
and put_char()?

	Regards
		Oliver

>From ac75a2c9ea67ec22c704a6bcaa30e6fc415d64d3 Mon Sep 17 00:00:00 2001
From: Oliver Neukum <oneukum@suse.com>
Date: Wed, 21 Oct 2015 12:10:07 +0200
Subject: [PATCH] cdc-acm: implement put_char() and flush_chars()

This should cut down latencies and waste if the tty layer writes single bytes.

Signed-off-by: Oliver Neukum >oneukum@suse.com>
---
 drivers/usb/class/cdc-acm.c | 58 +++++++++++++++++++++++++++++++++++++++++++++
 drivers/usb/class/cdc-acm.h |  1 +
 2 files changed, 59 insertions(+)

diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
index b30e742..262f179 100644
--- a/drivers/usb/class/cdc-acm.c
+++ b/drivers/usb/class/cdc-acm.c
@@ -725,6 +725,62 @@ static int acm_tty_write(struct tty_struct *tty,
 	return count;
 }
 
+static void acm_tty_flush_chars(struct tty_struct *tty)
+{
+	struct acm *acm = tty->driver_data;
+	struct acm_wb *cur = acm->putbuffer;
+	int err;
+	unsigned long flags;
+
+	acm->putbuffer = NULL;
+	err = usb_autopm_get_interface_async(acm->control);
+	spin_lock_irqsave(&acm->write_lock, flags);
+	if (err < 0) {
+		cur->use = 0;
+		goto out;
+	}
+
+	if (acm->susp_count) {
+		usb_anchor_urb(cur->urb, &acm->delayed);
+		goto out;
+	}
+
+	acm_start_wb(acm, cur);
+out:
+	spin_unlock_irqrestore(&acm->write_lock, flags);
+	return;
+}
+
+static int acm_tty_put_char(struct tty_struct *tty, unsigned char ch)
+{
+	struct acm *acm = tty->driver_data;
+	struct acm_wb *cur;
+	int wbn;
+	unsigned long flags;
+
+overflow:
+	cur = acm->putbuffer;
+	if (!cur) {
+		spin_lock_irqsave(&acm->write_lock, flags);
+		wbn = acm_wb_alloc(acm);
+		if (wbn >= 0) {
+			cur = &acm->wb[wbn];
+			acm->putbuffer = cur;
+		}
+		spin_unlock_irqrestore(&acm->write_lock, flags);
+		if (!cur)
+			return 0;
+	}
+
+	if (cur->len == acm->writesize) {
+		acm_tty_flush_chars(tty);
+		goto overflow;
+	}
+
+	cur->buf[cur->len++] = ch;
+	return 1;
+}
+
 static int acm_tty_write_room(struct tty_struct *tty)
 {
 	struct acm *acm = tty->driver_data;
@@ -1888,6 +1944,8 @@ static const struct tty_operations acm_ops = {
 	.cleanup =		acm_tty_cleanup,
 	.hangup =		acm_tty_hangup,
 	.write =		acm_tty_write,
+	.put_char =		acm_tty_put_char,
+	.flush_chars =		acm_tty_flush_chars,
 	.write_room =		acm_tty_write_room,
 	.ioctl =		acm_tty_ioctl,
 	.throttle =		acm_tty_throttle,
diff --git a/drivers/usb/class/cdc-acm.h b/drivers/usb/class/cdc-acm.h
index dd9af38..648a6f7 100644
--- a/drivers/usb/class/cdc-acm.h
+++ b/drivers/usb/class/cdc-acm.h
@@ -94,6 +94,7 @@ struct acm {
 	unsigned long read_urbs_free;
 	struct urb *read_urbs[ACM_NR];
 	struct acm_rb read_buffers[ACM_NR];
+	struct acm_wb *putbuffer;			/* for acm_tty_put_char() */
 	int rx_buflimit;
 	int rx_endpoint;
 	spinlock_t read_lock;
-- 
2.1.4

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 10/21/2015 06:12 AM, Oliver Neukum wrote:
> On Tue, 2015-10-20 at 14:16 -0400, Peter Hurley wrote:
>> ECHO is on by default and the cdc-acm driver does not implement the
>> put_char() and flush_chars() tty driver methods, which made the
>> problem
>> _way worse_, since every echoed char is sent as it's own URB.
> 
> That can be fixed. How can I test this?

I'm working on getting my tty tests organized for upstreaming, but it's
not there yet. Let me see if I can get you a standalone test for
accuracy, at least.

> Will the tty layer use write() and put_char()?

Echoing uses put_char() + flush_chars() for echoing, if the driver
supports it; otherwise, it uses write().

Be aware that while the N_TTY line discipline ensures that put_char()
and write() usage will not be interleaved without flush_chars(), other
line disciplines might not, so at least be sure that driver won't
crash if that happens.

Regards,
Peter Hurley


> From ac75a2c9ea67ec22c704a6bcaa30e6fc415d64d3 Mon Sep 17 00:00:00 2001
> From: Oliver Neukum <oneukum@suse.com>
> Date: Wed, 21 Oct 2015 12:10:07 +0200
> Subject: [PATCH] cdc-acm: implement put_char() and flush_chars()
> 
> This should cut down latencies and waste if the tty layer writes single bytes.
> 
> Signed-off-by: Oliver Neukum >oneukum@suse.com>
> ---
>  drivers/usb/class/cdc-acm.c | 58 +++++++++++++++++++++++++++++++++++++++++++++
>  drivers/usb/class/cdc-acm.h |  1 +
>  2 files changed, 59 insertions(+)
> 
> diff --git a/drivers/usb/class/cdc-acm.c b/drivers/usb/class/cdc-acm.c
> index b30e742..262f179 100644
> --- a/drivers/usb/class/cdc-acm.c
> +++ b/drivers/usb/class/cdc-acm.c
> @@ -725,6 +725,62 @@ static int acm_tty_write(struct tty_struct *tty,
>  	return count;
>  }
>  
> +static void acm_tty_flush_chars(struct tty_struct *tty)
> +{
> +	struct acm *acm = tty->driver_data;
> +	struct acm_wb *cur = acm->putbuffer;
> +	int err;
> +	unsigned long flags;
> +
> +	acm->putbuffer = NULL;
> +	err = usb_autopm_get_interface_async(acm->control);
> +	spin_lock_irqsave(&acm->write_lock, flags);
> +	if (err < 0) {
> +		cur->use = 0;
> +		goto out;
> +	}
> +
> +	if (acm->susp_count) {
> +		usb_anchor_urb(cur->urb, &acm->delayed);
> +		goto out;
> +	}
> +
> +	acm_start_wb(acm, cur);
> +out:
> +	spin_unlock_irqrestore(&acm->write_lock, flags);
> +	return;
> +}
> +
> +static int acm_tty_put_char(struct tty_struct *tty, unsigned char ch)
> +{
> +	struct acm *acm = tty->driver_data;
> +	struct acm_wb *cur;
> +	int wbn;
> +	unsigned long flags;
> +
> +overflow:
> +	cur = acm->putbuffer;
> +	if (!cur) {
> +		spin_lock_irqsave(&acm->write_lock, flags);
> +		wbn = acm_wb_alloc(acm);
> +		if (wbn >= 0) {
> +			cur = &acm->wb[wbn];
> +			acm->putbuffer = cur;
> +		}
> +		spin_unlock_irqrestore(&acm->write_lock, flags);
> +		if (!cur)
> +			return 0;
> +	}
> +
> +	if (cur->len == acm->writesize) {
> +		acm_tty_flush_chars(tty);
> +		goto overflow;
> +	}
> +
> +	cur->buf[cur->len++] = ch;
> +	return 1;
> +}
> +
>  static int acm_tty_write_room(struct tty_struct *tty)
>  {
>  	struct acm *acm = tty->driver_data;
> @@ -1888,6 +1944,8 @@ static const struct tty_operations acm_ops = {
>  	.cleanup =		acm_tty_cleanup,
>  	.hangup =		acm_tty_hangup,
>  	.write =		acm_tty_write,
> +	.put_char =		acm_tty_put_char,
> +	.flush_chars =		acm_tty_flush_chars,
>  	.write_room =		acm_tty_write_room,
>  	.ioctl =		acm_tty_ioctl,
>  	.throttle =		acm_tty_throttle,
> diff --git a/drivers/usb/class/cdc-acm.h b/drivers/usb/class/cdc-acm.h
> index dd9af38..648a6f7 100644
> --- a/drivers/usb/class/cdc-acm.h
> +++ b/drivers/usb/class/cdc-acm.h
> @@ -94,6 +94,7 @@ struct acm {
>  	unsigned long read_urbs_free;
>  	struct urb *read_urbs[ACM_NR];
>  	struct acm_rb read_buffers[ACM_NR];
> +	struct acm_wb *putbuffer;			/* for acm_tty_put_char() */
>  	int rx_buflimit;
>  	int rx_endpoint;
>  	spinlock_t read_lock;
> 

Re: [PATCH] Fix data loss in cdc-acm

[Peter Hurley]

On 10/21/2015 08:09 AM, Peter Hurley wrote:
> Be aware that while the N_TTY line discipline ensures that put_char()
> and write() usage will not be interleaved without flush_chars(), other
> line disciplines might not, so at least be sure that driver won't
> crash if that happens.

Sorry, I take that back: certain echoes are output via write() in
OPOST mode, specifically for O_ONLCR and XTABS.