ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

Every now and then I see in dmesg:

[Wed May 20 14:03:16 2020] cdc_ether 1-6.2:1.0 usb0: unregister 'cdc_ether' usb-0000:00:14.0-6.2, CDC Ethernet Device
[Wed May 20 14:03:25 2020] usb usb1-port6: disabled by hub (EMI?), re-enabling...
[Wed May 20 14:03:25 2020] usb 1-6: USB disconnect, device number 85
[Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
[Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
[Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
[Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
[Wed May 20 14:03:26 2020] usb 1-6: new high-speed USB device number 94 using xhci_hcd
[Wed May 20 14:03:27 2020] hub 1-6:1.0: USB hub found
[Wed May 20 14:03:27 2020] hub 1-6:1.0: 3 ports detected
[Wed May 20 14:03:27 2020] usb 1-6.2: new high-speed USB device number 95 using xhci_hcd
[Wed May 20 14:03:27 2020] cdc_ether 1-6.2:1.0 usb0: register 'cdc_ether' at usb-0000:00:14.0-6.2, CDC Ethernet Device, 7e:1d:06:c0:3f:3c
[Wed May 20 14:03:27 2020] usb 1-6.3: new high-speed USB device number 96 using xhci_hcd
[Wed May 20 14:03:27 2020] cdc_acm 1-6.3:1.1: ttyACM0: USB ACM device

This (EMI?) disconnect causes 2 things.
1) I loose the TTY temporarily and have to reconnect.
2) After reconnect there are garbage chars on the gadget side, such as:
     h�^@^@� ^@^@� ^@
   or
     X���)H��4Ğ^���
   which causes confusion on for the tty/bash on the gadget.

The disconnect is mostly just annoying but the garbage chars are a major pain, one cannot trust
that cmds are understod. Is there a bug in ttyACM driver causing these?

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Montag, den 25.05.2020, 14:46 +0000 schrieb Joakim Tjernlund:

> This (EMI?) disconnect causes 2 things.
> 1) I loose the TTY temporarily and have to reconnect.

Unfortunately I see no way to reestablish contact transparantly
on the level of the driver.

> 2) After reconnect there are garbage chars on the gadget side, such as:
>      h�^@^@� ^@^@� ^@

This looks like MM is acting up in user space.

>    or
>      X���)H��4Ğ^���
>    which causes confusion on for the tty/bash on the gadget.
> 
> The disconnect is mostly just annoying but the garbage chars are a major pain, one cannot trust
> that cmds are understod. Is there a bug in ttyACM driver causing these?

Hi,

thanks for the bug report. The most likely cause of your problem is
ModemManager probing the new device. It has a blacklist.

	HTH
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Mon, 2020-05-25 at 17:02 +0200, Oliver Neukum wrote:
> CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> 
> 
> Am Montag, den 25.05.2020, 14:46 +0000 schrieb Joakim Tjernlund:
> 
> > This (EMI?) disconnect causes 2 things.
> > 1) I loose the TTY temporarily and have to reconnect.
> 
> Unfortunately I see no way to reestablish contact transparantly
> on the level of the driver.
> 
> > 2) After reconnect there are garbage chars on the gadget side, such as:
> >      h�^@^@� ^@^@� ^@
> 
> This looks like MM is acting up in user space.
> 
> >    or
> >      X���)H��4Ğ^���
> >    which causes confusion on for the tty/bash on the gadget.
> > 
> > The disconnect is mostly just annoying but the garbage chars are a major pain, one cannot trust
> > that cmds are understod. Is there a bug in ttyACM driver causing these?
> 
> Hi,
> 
> thanks for the bug report. The most likely cause of your problem is
> ModemManager probing the new device. It has a blacklist.


No, I have already blacklisted this device from modemmanger, is blacklist not reliable in this case?

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Mon, 2020-05-25 at 17:15 +0200, Joakim Tjernlund wrote:
> On Mon, 2020-05-25 at 17:02 +0200, Oliver Neukum wrote:
> > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > 
> > 
> > Am Montag, den 25.05.2020, 14:46 +0000 schrieb Joakim Tjernlund:
> > 
> > > This (EMI?) disconnect causes 2 things.
> > > 1) I loose the TTY temporarily and have to reconnect.
> > 
> > Unfortunately I see no way to reestablish contact transparantly
> > on the level of the driver.
> > 
> > > 2) After reconnect there are garbage chars on the gadget side, such as:
> > >      h�^@^@� ^@^@� ^@
> > 
> > This looks like MM is acting up in user space.
> > 
> > >    or
> > >      X���)H��4Ğ^���
> > >    which causes confusion on for the tty/bash on the gadget.
> > > 
> > > The disconnect is mostly just annoying but the garbage chars are a major pain, one cannot trust
> > > that cmds are understod. Is there a bug in ttyACM driver causing these?
> > 
> > Hi,
> > 
> > thanks for the bug report. The most likely cause of your problem is
> > ModemManager probing the new device. It has a blacklist.
> 
> No, I have already blacklisted this device from modemmanger, is blacklist not reliable in this case?
> 
>  Jocke
> 

To be clear, I can pull the cable and put it back and there are no garbage chars.
There is also this error:
[Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
[Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
[Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
[Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts

Should not this auto reenable emulate reattaching the USB cable?

     Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:

> To be clear, I can pull the cable and put it back and there are no garbage chars.
> There is also this error:
> [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> 
> Should not this auto reenable emulate reattaching the USB cable?

Hi,

yes it should. You find the garage characters after the EMI event. How
sure are you that they arrive after the event and not during the event?

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Tue, 2020-05-26 at 10:47 +0200, Oliver Neukum wrote:
> 
> Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:
> 
> > To be clear, I can pull the cable and put it back and there are no garbage chars.
> > There is also this error:
> > [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> > [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> > [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> > [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > 
> > Should not this auto reenable emulate reattaching the USB cable?
> 
> Hi,
> 
> yes it should. You find the garage characters after the EMI event. How
> sure are you that they arrive after the event and not during the event?
> 

Don't known how to determine that? 
I can say that 
   acm_ctrl_irq - usb_submit_urb failed: -19
and
   cdc_acm 1-6.3:1.1: failed to set dtr/rts
are unique to this EMI event though. It does not feel like this
reenabling follow the same procedure as a cable pull?
As I can only see the above two errors I think we should get rid of
these first.

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Dienstag, den 26.05.2020, 08:59 +0000 schrieb Joakim Tjernlund:
> On Tue, 2020-05-26 at 10:47 +0200, Oliver Neukum wrote:
> > 
> > Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:
> > 
> > > To be clear, I can pull the cable and put it back and there are no garbage chars.
> > > There is also this error:
> > > [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> > > [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> > > [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> > > [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > > 
> > > Should not this auto reenable emulate reattaching the USB cable?
> > 
> > Hi,
> > 
> > yes it should. You find the garage characters after the EMI event. How
> > sure are you that they arrive after the event and not during the event?
> > 
> 
> Don't known how to determine that? 
> I can say that 
>    acm_ctrl_irq - usb_submit_urb failed: -19

-19 is -ENODEV

The driver thinks tries to resubmit the URB asking for control
messages.
Basically you are seeing error handling starting and failing due
to a subsequent disconnect.
 
> and
>    cdc_acm 1-6.3:1.1: failed to set dtr/rts
> are unique to this EMI event though. It does not feel like this
> reenabling follow the same procedure as a cable pull?
> As I can only see the above two errors I think we should get rid of
> these first.

The timing is different and if there is EMI transfer can end
in errors and cause error handling to kick in. You are seeing
symptoms. You can try enabling dynamic debugging to get
a better log.

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Tue, 2020-05-26 at 12:14 +0200, Oliver Neukum wrote:
> CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> 
> 
> Am Dienstag, den 26.05.2020, 08:59 +0000 schrieb Joakim Tjernlund:
> > On Tue, 2020-05-26 at 10:47 +0200, Oliver Neukum wrote:
> > > Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:
> > > 
> > > > To be clear, I can pull the cable and put it back and there are no garbage chars.
> > > > There is also this error:
> > > > [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> > > > [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> > > > [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> > > > [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > > > 
> > > > Should not this auto reenable emulate reattaching the USB cable?
> > > 
> > > Hi,
> > > 
> > > yes it should. You find the garage characters after the EMI event. How
> > > sure are you that they arrive after the event and not during the event?
> > > 
> > 
> > Don't known how to determine that?
> > I can say that
> >    acm_ctrl_irq - usb_submit_urb failed: -19
> 
> -19 is -ENODEV
> 
> The driver thinks tries to resubmit the URB asking for control
> messages.
> Basically you are seeing error handling starting and failing due
> to a subsequent disconnect.
> 
> > and
> >    cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > are unique to this EMI event though. It does not feel like this
> > reenabling follow the same procedure as a cable pull?
> > As I can only see the above two errors I think we should get rid of
> > these first.
> 
> The timing is different and if there is EMI transfer can end
> in errors and cause error handling to kick in. You are seeing
> symptoms. You can try enabling dynamic debugging to get
> a better log.
> 
>         Regards
>                 Oliver
> 

Tried som dynamic debug for module cdc_acm got something I cannot parse:
[Tue May 26 18:24:30 2020] cdc_acm 1-6.3:1.1: ttyACM0: USB ACM device
[Tue May 26 18:24:30 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[Tue May 26 18:24:43 2020] usb 1-6.2: new high-speed USB device number 36 using xhci_hcd
[Tue May 26 18:24:43 2020] cdc_ether 1-6.2:1.0 usb0: register 'cdc_ether' at usb-0000:00:14.0-6.2, CDC Ethernet Device, 92:d1:c9:b4:91:d5
[Tue May 26 18:24:43 2020] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready
[Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_tty_set_termios - set line: 115200 0 0 8
[Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
[Tue May 26 18:25:42 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - urb shutting down with status: -2
[Tue May 26 18:25:42 2020] cdc_acm 1-6.3:1.2: acm_read_bulk_callback - urb shutting down with status: -2
....

I do note one thing in:

First connect after power on for the gadget I see some garbage chars when connecting with cu.
However, if I just do a "cat /dev/ttyACM0", Ctrl-C and then cu I there are no garbage chars.

It feels like the gadget is spewing some garbage at power on and this gets saved in hosts cdc_acm, once
I open /dev/ttyACM0 for write, these gets echoed back to the gadget.
If so, cdc_acm fails to clear its buffers before the first open, does this make sense to you?

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Tue, 2020-05-26 at 18:46 +0200, Joakim Tjernlund wrote:
> On Tue, 2020-05-26 at 12:14 +0200, Oliver Neukum wrote:
> > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > 
> > 
> > Am Dienstag, den 26.05.2020, 08:59 +0000 schrieb Joakim Tjernlund:
> > > On Tue, 2020-05-26 at 10:47 +0200, Oliver Neukum wrote:
> > > > Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:
> > > > 
> > > > > To be clear, I can pull the cable and put it back and there are no garbage chars.
> > > > > There is also this error:
> > > > > [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> > > > > [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> > > > > [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> > > > > [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > > > > 
> > > > > Should not this auto reenable emulate reattaching the USB cable?
> > > > 
> > > > Hi,
> > > > 
> > > > yes it should. You find the garage characters after the EMI event. How
> > > > sure are you that they arrive after the event and not during the event?
> > > > 
> > > 
> > > Don't known how to determine that?
> > > I can say that
> > >    acm_ctrl_irq - usb_submit_urb failed: -19
> > 
> > -19 is -ENODEV
> > 
> > The driver thinks tries to resubmit the URB asking for control
> > messages.
> > Basically you are seeing error handling starting and failing due
> > to a subsequent disconnect.
> > 
> > > and
> > >    cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > > are unique to this EMI event though. It does not feel like this
> > > reenabling follow the same procedure as a cable pull?
> > > As I can only see the above two errors I think we should get rid of
> > > these first.
> > 
> > The timing is different and if there is EMI transfer can end
> > in errors and cause error handling to kick in. You are seeing
> > symptoms. You can try enabling dynamic debugging to get
> > a better log.
> > 
> >         Regards
> >                 Oliver
> > 
> 
> Tried som dynamic debug for module cdc_acm got something I cannot parse:
> [Tue May 26 18:24:30 2020] cdc_acm 1-6.3:1.1: ttyACM0: USB ACM device
> [Tue May 26 18:24:30 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
> [Tue May 26 18:24:43 2020] usb 1-6.2: new high-speed USB device number 36 using xhci_hcd
> [Tue May 26 18:24:43 2020] cdc_ether 1-6.2:1.0 usb0: register 'cdc_ether' at usb-0000:00:14.0-6.2, CDC Ethernet Device, 92:d1:c9:b4:91:d5
> [Tue May 26 18:24:43 2020] IPv6: ADDRCONF(NETDEV_UP): usb0: link is not ready
> [Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
> [Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_tty_set_termios - set line: 115200 0 0 8
> [Tue May 26 18:25:40 2020] cdc_acm 1-6.3:1.1: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7
> [Tue May 26 18:25:42 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - urb shutting down with status: -2
> [Tue May 26 18:25:42 2020] cdc_acm 1-6.3:1.2: acm_read_bulk_callback - urb shutting down with status: -2
> ....
> 
> I do note one thing in:
> 
> First connect after power on for the gadget I see some garbage chars when connecting with cu.
> However, if I just do a "cat /dev/ttyACM0", Ctrl-C and then cu I there are no garbage chars.
> 
> It feels like the gadget is spewing some garbage at power on and this gets saved in hosts cdc_acm, once
> I open /dev/ttyACM0 for write, these gets echoed back to the gadget.
> If so, cdc_acm fails to clear its buffers before the first open, does this make sense to you?
> 

Got some evidence now, I change the default baud rate form 9600 to 115200 in cdc_acm and now
I can see(instead of garbage chars):
cu usbacm0
Connected.
^@



U-Boot SPL


This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm 
and gets echoed back when I open ttyACM0

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> 
> 
> This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm 
> and gets echoed back when I open ttyACM0

Hi,

that makes sense, but it is not something that we could really
change in CDC-ACM, I am afraid.

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> 
> 
> Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > 
> > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > and gets echoed back when I open ttyACM0
> 
> Hi,
> 
> that makes sense, but it is not something that we could really
> change in CDC-ACM, I am afraid.

Why not? CDC-ACM should echo back anything it has received before open of ttyACM

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Greg KH]

On Wed, May 27, 2020 at 09:40:47AM +0000, Joakim Tjernlund wrote:
> On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > 
> > 
> > Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > > 
> > > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > > and gets echoed back when I open ttyACM0
> > 
> > Hi,
> > 
> > that makes sense, but it is not something that we could really
> > change in CDC-ACM, I am afraid.
> 
> Why not? CDC-ACM should echo back anything it has received before open of ttyACM

Is that in the specification somewhere?  I don't think there is any
requirement, otherwise that could be a huge waste of memory, right?  How
many bytes do you "keep" around?

thanks,

greg k-h

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Mittwoch, den 27.05.2020, 09:40 +0000 schrieb Joakim Tjernlund:
> On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > 
> > 
> > Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > > 
> > > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > > and gets echoed back when I open ttyACM0
> > 
> > Hi,
> > 
> > that makes sense, but it is not something that we could really
> > change in CDC-ACM, I am afraid.
> 
> Why not? CDC-ACM should echo back anything it has received before open of ttyACM

Well, there is an inherent race condition with loading the module I am
afraid. By default cdc-acm should actually echo. You can set the
DISABLE_ECHO echo quirk for your device if you want to get rid of it.

Is CDC-ACM violating some standard with respect to echoing? Changing
defaults really hurts users, no matter what you do.

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Wed, 2020-05-27 at 12:41 +0200, Oliver Neukum wrote:
> Am Mittwoch, den 27.05.2020, 09:40 +0000 schrieb Joakim Tjernlund:
> > On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> > > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > > 
> > > 
> > > Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > > > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > > > and gets echoed back when I open ttyACM0
> > > 
> > > Hi,
> > > 
> > > that makes sense, but it is not something that we could really
> > > change in CDC-ACM, I am afraid.
> > 
> > Why not? CDC-ACM should echo back anything it has received before open of ttyACM
> 
> Well, there is an inherent race condition with loading the module I am
> afraid. By default cdc-acm should actually echo. You can set the
> DISABLE_ECHO echo quirk for your device if you want to get rid of it.
> 
> Is CDC-ACM violating some standard with respect to echoing? Changing
> defaults really hurts users, no matter what you do.
> 


	/*
	 * Suppress initial echoing for some devices which might send data
	 * immediately after acm driver has been installed.
	 */
	if (acm->quirks & DISABLE_ECHO)
		tty->termios.c_lflag &= ~ECHO;

That seems to be what I needed, should be default I think ...
Need to test som more but looks much better.
I guess all cdc_acm's are could suffer from this? Will depend the target in the other
end.

 Jocke 

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Wed, 2020-05-27 at 15:16 +0200, Joakim Tjernlund wrote:
> On Wed, 2020-05-27 at 12:41 +0200, Oliver Neukum wrote:
> > Am Mittwoch, den 27.05.2020, 09:40 +0000 schrieb Joakim Tjernlund:
> > > On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> > > > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > > > 
> > > > 
> > > > Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > > > > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > > > > and gets echoed back when I open ttyACM0
> > > > 
> > > > Hi,
> > > > 
> > > > that makes sense, but it is not something that we could really
> > > > change in CDC-ACM, I am afraid.
> > > 
> > > Why not? CDC-ACM should echo back anything it has received before open of ttyACM
> > 
> > Well, there is an inherent race condition with loading the module I am
> > afraid. By default cdc-acm should actually echo. You can set the
> > DISABLE_ECHO echo quirk for your device if you want to get rid of it.
> > 
> > Is CDC-ACM violating some standard with respect to echoing? Changing
> > defaults really hurts users, no matter what you do.
> > 
> 
> 	/*
> 	 * Suppress initial echoing for some devices which might send data
> 	 * immediately after acm driver has been installed.
> 	 */
> 	if (acm->quirks & DISABLE_ECHO)
> 		tty->termios.c_lflag &= ~ECHO;
> 
> That seems to be what I needed, should be default I think ...
> Need to test som more but looks much better.
> I guess all cdc_acm's are could suffer from this? Will depend the target in the other
> end.
> 

Would be nice if the ECHO could be delay until first read(2)/termios_set, the baudrate could be 11500 until open(2) too, maybe

However, the bigger question: Is the a way to configure Windows to default to ~ECHO too ?

    Jocke 

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Wed, 2020-05-27 at 17:41 +0200, Joakim Tjernlund wrote:
> On Wed, 2020-05-27 at 15:16 +0200, Joakim Tjernlund wrote:
> > On Wed, 2020-05-27 at 12:41 +0200, Oliver Neukum wrote:
> > > Am Mittwoch, den 27.05.2020, 09:40 +0000 schrieb Joakim Tjernlund:
> > > > On Wed, 2020-05-27 at 10:38 +0200, Oliver Neukum wrote:
> > > > > CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.
> > > > > 
> > > > > 
> > > > > Am Dienstag, den 26.05.2020, 17:19 +0000 schrieb Joakim Tjernlund:
> > > > > > This "u-boot SPL" is the first thing u-boot writes and somehow this is remembered, I assume, by cdc_acm
> > > > > > and gets echoed back when I open ttyACM0
> > > > > 
> > > > > Hi,
> > > > > 
> > > > > that makes sense, but it is not something that we could really
> > > > > change in CDC-ACM, I am afraid.
> > > > 
> > > > Why not? CDC-ACM should echo back anything it has received before open of ttyACM
> > > 
> > > Well, there is an inherent race condition with loading the module I am
> > > afraid. By default cdc-acm should actually echo. You can set the
> > > DISABLE_ECHO echo quirk for your device if you want to get rid of it.
> > > 
> > > Is CDC-ACM violating some standard with respect to echoing? Changing
> > > defaults really hurts users, no matter what you do.

I can see that when I open the tty, a USB read is performed and then echoed back.
Should an open really do that?
If so, an flag to open(2), telling it to drop the input buffer would be really handy.

 Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Freitag, den 05.06.2020, 10:09 +0000 schrieb Joakim Tjernlund:

> I can see that when I open the tty, a USB read is performed and then echoed back.
> Should an open really do that?

Yes. The tty interface does not pass read(2) down to the driver.

> If so, an flag to open(2), telling it to drop the input buffer would be really handy.

That actually looks like an unavoidable race condition to me.
How would you tell the difference between old data and newly
arriving data?

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Mon, 2020-06-08 at 11:13 +0200, Oliver Neukum wrote:
> 
> Am Freitag, den 05.06.2020, 10:09 +0000 schrieb Joakim Tjernlund:
> 
> > I can see that when I open the tty, a USB read is performed and then echoed back.
> > Should an open really do that?
> 
> Yes. The tty interface does not pass read(2) down to the driver.
> 
> > If so, an flag to open(2), telling it to drop the input buffer would be really handy.
> 
> That actually looks like an unavoidable race condition to me.
> How would you tell the difference between old data and newly
> arriving data?

Most terminal programs I use tries to empty the read queue after open, just to avoid
old garbage så I don't see a problem here. It it up to the terminal app.
Maybe one could use O_DIRECT for this purpose ?

   Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Montag, den 08.06.2020, 11:39 +0000 schrieb Joakim Tjernlund:

> Most terminal programs I use tries to empty the read queue after open, just to avoid
> old garbage så I don't see a problem here. It it up to the terminal app.
> Maybe one could use O_DIRECT for this purpose ?

Well, we can throw away stuff received until some time in open(2).
But you can always have stuff in the buffer when open(2) returns.
User space needs to be ready to deal with stuff in the buffer.

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Mon, 2020-06-08 at 17:40 +0200, Oliver Neukum wrote:
> 
> Am Montag, den 08.06.2020, 11:39 +0000 schrieb Joakim Tjernlund:
> 
> > Most terminal programs I use tries to empty the read queue after open, just to avoid
> > old garbage så I don't see a problem here. It it up to the terminal app.
> > Maybe one could use O_DIRECT for this purpose ?
> 
> Well, we can throw away stuff received until some time in open(2).
> But you can always have stuff in the buffer when open(2) returns.
> User space needs to be ready to deal with stuff in the buffer.

User space already does this, but the automatic ECHOing that happens at open
is not possible to address in user space. The buffered chars are sent to both
the terminal app(putty/minicom etc.) and over the wire to the shell waiting there
and that is the problem. There is no way to prevent that ECHO back over the wire(USB)
as the default is to ECHO and one have to open the tty to change to non ECHO.

    Jocke

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Oliver Neukum]

Am Montag, den 08.06.2020, 16:00 +0000 schrieb Joakim Tjernlund:

> User space already does this, but the automatic ECHOing that happens at open
> is not possible to address in user space. The buffered chars are sent to both
> the terminal app(putty/minicom etc.) and over the wire to the shell waiting there
> and that is the problem. There is no way to prevent that ECHO back over the wire(USB)
> as the default is to ECHO and one have to open the tty to change to non ECHO.

Hi,

this is correct, but not specific to CDC-ACM. Could you ask the serial
maintainers and look at what SUS respectively POSIX have to say about
correct behavior?

	Regards
		Oliver

Re: ttyACM: disabled by hub (EMI?), re-enabling... Causes garbage chars & disconnect

[Joakim Tjernlund]

On Tue, 2020-05-26 at 10:59 +0200, Joakim Tjernlund wrote:
> On Tue, 2020-05-26 at 10:47 +0200, Oliver Neukum wrote:
> > Am Montag, den 25.05.2020, 16:49 +0000 schrieb Joakim Tjernlund:
> > 
> > > To be clear, I can pull the cable and put it back and there are no garbage chars.
> > > There is also this error:
> > > [Wed May 20 14:03:25 2020] cdc_acm 1-6.3:1.1: acm_ctrl_irq - usb_submit_urb failed: -19
> > > [Wed May 20 14:03:25 2020] usb 1-6-port2: attempt power cycle
> > > [Wed May 20 14:03:26 2020] usb 1-6.3: USB disconnect, device number 86
> > > [Wed May 20 14:03:26 2020] cdc_acm 1-6.3:1.1: failed to set dtr/rts
> > > 
> > > Should not this auto reenable emulate reattaching the USB cable?
> > 
> > Hi,
> > 
> > yes it should. You find the garage characters after the EMI event. How
> > sure are you that they arrive after the event and not during the event?
> > 
> 
> Don't known how to determine that? 
> I can say that 
>    acm_ctrl_irq - usb_submit_urb failed: -19
> and
>    cdc_acm 1-6.3:1.1: failed to set dtr/rts
> are unique to this EMI event though. It does not feel like this
> reenabling follow the same procedure as a cable pull?
> As I can only see the above two errors I think we should get rid of
> these first.
> 
>  Jocke

Been doing some more testing and found some interesting points for this
   disabled by hub (EMI?), re-enabling...
error message:

1) I does not happen on Windows.
2) It only happens when rebooting the UDC device and always after the hosts has seen a:
    cdc_ether 1-11.2:1.0 usb0: unregister 'cdc_ether' usb-0000:00:14.0-11.2, CDC Ethernet Device

Maybe some race in CDC tear down ?

   Jocke