Clever Geek Handbook

Linux cdc_acm device - unexpected characters sent to device

I am having problems with unexpected characters being sent to the USB port with the cdc_acm driver. What makes this even more difficult is that the code works fine on Ubuntu 12.04 (3.2 kernel), but does not work (topic of this question) on Centos 6 (3.6 kernel)

The USB device is a Bluegiga BLED112 Bluetooth Smart Bluetooth Dongle. Its built-in microcontroller will reset at any time if the USB interface is unexpectedly entered on it.

The verification code opens the port, writes 4 bytes (hello message) and expects to read the response. The read never completes because unexpected characters cause the device to reset causing the hub to delete the device and re-enumerate.

To troubleshoot, here's what I did:

  • Downloaded the source code for the cdc_acm driver. Added a bunch of printk and stack_dumps debug messages to keep track of what's going on.
  • I rmmmod 'stock' cdc_acm and insmod'd my toolbox. All device enumerations work, the right driver is connected, etc.
  • Since the code works on Ubuntu 12.04 / Linux 3.2, I grabbed the 3.2 cdc_acm code and compiled this module on Centos 6 / Linux 3.6 platform. Using this 3.2 module instead of 3.6 did not help. I went back to module 3.6.
  • Enabled the debug filesystem with usbmon and watched the USB traffic. I see additional characters being sent to the USB interface.
  • To see what happens on top of printk in the cdc_acm module, I concatenated the output of usb mon (cat / sys / kernel / debug / usb / usbmon / 3u | logger) and the output of the test application (scan_example / dev / ttyACM0 | logger -s). so I have one time stream correlated with a debug trace.
  • The bogus characters sent to the USB endpoint are x5E x40 x5E x40 x5E x40 x5E x40 x41 (in ASCII its ^ @ ^ @ ^ @ ^ @A) which looks like some sort of investigation or trying to get the attention of modem These characters are sent right away after the write () application forces 4 bytes of hello to be sent to the endpoint.

  • Since the cdc_acm device needs to be modem I tried to disable modem control by adding it to usb_device_id acm_ids [] in cdc_acm.c

    /* bluegiga BLED112*/
{ USB_DEVICE(0x2458, 0x0001),
.driver_info = NOT_A_MODEM,
},

  • The recompiled both insmod'd and syslog show it was recognized (quirks - 8), but no change in function.

Neither NetowrkManager nor Modem Manager works, but I still suspect that some modem control function is happening somewhere, I just don't know where.

Here's the annotated debug log (MDV prefix of those printk I added to cdc_acm)

Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_bulk
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_done

Here are 4 bytes sent by the app 00 00 00 01

Feb 13 18:14:32 localhost cpcenter: df046a80 3672670191 C Bi:3:006:4 0 4 = 00000001
Feb 13 18:14:32 localhost cpcenter: 1360797272.669690 write: data2: len=0 contains:

... and these extra characters appear unexpectedly 5e 40 5e 40 5e 40 ....

Feb 13 18:14:32 localhost cpcenter: df046a80 3672670232 S Bi:3:006:4 -115 128 <
Feb 13 18:14:32 localhost cpcenter: f3cc5740 3672670297 S Bo:3:006:4 -115 1 = 5e
Feb 13 18:14:32 localhost cpcenter: df2e1300 3672670332 S Bo:3:006:4 -115 1 = 40
Feb 13 18:14:32 localhost cpcenter: f3cc5740 3672670347 C Bo:3:006:4 0 1 >
Feb 13 18:14:32 localhost cpcenter: f3cc5740 3672670392 S Bo:3:006:4 -115 1 = 5e
Feb 13 18:14:32 localhost cpcenter: df2e1180 3672670426 S Bo:3:006:4 -115 1 = 40
Feb 13 18:14:32 localhost cpcenter: df2e1c00 3672670461 S Bo:3:006:4 -115 1 = 5e
Feb 13 18:14:32 localhost cpcenter: df2e1840 3672670496 S Bo:3:006:4 -115 1 = 40
Feb 13 18:14:32 localhost cpcenter: df2e1300 3672670591 C Bo:3:006:4 0 1 >

At this point, we get a spontaneous disconnection.

Feb 13 18:14:32 localhost kernel: usb 3-1: USB disconnect, device number 6
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_bulk
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_done
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm read_bulk_callback
Feb 13 18:14:32 localhost kernel: MDV 1 acm_read_bulk_callback - urb 1, len 0
Feb 13 18:14:32 localhost kernel: MDV 3 acm_read_bulk_callback - non-zero urb status: -71
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_bulk
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_done
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm read_bulk_callback
Feb 13 18:14:32 localhost kernel: MDV 1 acm_read_bulk_callback - urb 1, len 0
Feb 13 18:14:32 localhost kernel: MDV 3 acm_read_bulk_callback - non-zero urb status: -71
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_bulk
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_done
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm read_bulk_callback
Feb 13 18:14:32 localhost kernel: MDV 1 acm_read_bulk_callback - urb 2, len 0
Feb 13 18:14:32 localhost cpcenter: df2e1d80 3672670629 S Bo:3:006:4 -115 1 = 5e
Feb 13 18:14:32 localhost kernel: MDV 3 acm_read_bulk_callback - non-zero urb status: -71
Feb 13 18:14:32 localhost cpcenter: df2e1300 3672670677 S Bo:3:006:4 -115 1 = 41
Feb 13 18:14:32 localhost cpcenter: f3cc5740 3672670802 C Bo:3:006:4 0 1 >
Feb 13 18:14:32 localhost cpcenter: df2e1180 3672671019 C Bo:3:006:4 0 1 >
Feb 13 18:14:32 localhost cpcenter: df2e1c00 3672671237 C Bo:3:006:4 0 1 >
Feb 13 18:14:32 localhost cpcenter: dfbf8c00 3672673193 C Ii:3:001:1 0:2048 1 = 02
Feb 13 18:14:32 localhost cpcenter: dfbf8c00 3672673207 S Ii:3:001:1 -115:2048 4 <
Feb 13 18:14:32 localhost cpcenter: f3c26c00 3672673221 S Ci:3:001:0 s a3 00 0000 0001 0004 4 <
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_disconnect
Feb 13 18:14:32 localhost kernel: Pid: 29, comm: khubd Tainted: G           O 3.5.3-1.el6.elrepo.i686 #1

Stack trace during shutdown

Feb 13 18:14:32 localhost kernel: Call Trace:
Feb 13 18:14:32 localhost kernel: [<f82dabc5>] acm_disconnect+0x35/0x1f0 [cdc_acm]
Feb 13 18:14:32 localhost kernel: [<c13835db>] usb_unbind_interface+0x4b/0x180
Feb 13 18:14:32 localhost cpcenter: f3c26c00 3672673239 C Ci:3:001:0 0 4 = 00010100
Feb 13 18:14:32 localhost kernel: [<c1318bfb>] __device_release_driver+0x5b/0xb0
Feb 13 18:14:32 localhost kernel: [<c1318d05>] device_release_driver+0x25/0x40
Feb 13 18:14:32 localhost kernel: [<c1317f0c>] bus_remove_device+0xcc/0x130
Feb 13 18:14:32 localhost kernel: [<c131612f>] ? device_remove_attrs+0x2f/0x90
Feb 13 18:14:32 localhost kernel: [<c1316275>] device_del+0xe5/0x180
Feb 13 18:14:32 localhost kernel: [<c1380326>] usb_disable_device+0x96/0x240    Feb 13 18:14:32 localhost kernel: [<c1379f91>] usb_disconnect+0x91/0x130
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_bulk
Feb 13 18:14:32 localhost kernel: [<c137a2c0>] hub_port_connect_change+0xb0/0xa60
Feb 13 18:14:32 localhost kernel: [<c1380f4e>] ? usb_control_msg+0xce/0xe0
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm acm_write_done
Feb 13 18:14:32 localhost kernel: [<c137b296>] hub_events+0x536/0x810
Feb 13 18:14:32 localhost cpcenter: f3c26c00 3672673243 S Co:3:001:0 s 23 01 0010 0001 0000 0
Feb 13 18:14:32 localhost cpcenter: f3c26c00 3672673250 C Co:3:001:0 0 0
Feb 13 18:14:32 localhost kernel: [<c1065bdf>] ? finish_wait+0x4f/0x70
Feb 13 18:14:32 localhost kernel: [<c137b5aa>] hub_thread+0x3a/0x1d0
Feb 13 18:14:32 localhost cpcenter: df2e1840 3672673260 C Bo:3:006:4 -71 0
Feb 13 18:14:32 localhost kernel: [<c1065a70>] ? wake_up_bit+0x30/0x30
Feb 13 18:14:32 localhost kernel: [<c137b570>] ? hub_events+0x810/0x810
Feb 13 18:14:32 localhost kernel: [<c106564c>] kthread+0x7c/0x90
Feb 13 18:14:32 localhost cpcenter: f3c16c80 3672673292 C Bi:3:006:4 -71 0
Feb 13 18:14:32 localhost cpcenter: df2e1d80 3672673453 C Bo:3:006:4 -71 0
Feb 13 18:14:32 localhost cpcenter: f3c16d40 3672673553 C Bi:3:006:4 -71 0
Feb 13 18:14:32 localhost kernel: [<c10655d0>] ? kthread_freezable_should_stop+0x60/0x60
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm read_bulk_callback
Feb 13 18:14:32 localhost kernel: [<c14dedbe>] kernel_thread_helper+0x6/0x10
Feb 13 18:14:32 localhost kernel: MDV 1 acm_read_bulk_callback - urb 3, len 0
Feb 13 18:14:32 localhost kernel: MDV:cdc-acm stop_data_traffic
Feb 13 18:14:32 localhost cpcenter: f3d19500 3672674474 C Ii:3:006:2 -108:64 0
Feb 13 18:14:32 localhost kernel: MDV 2 acm_read_bulk_callback - disconnected
Feb 13 18:14:32 localhost cpcenter: df2e1300 3672674636 C Bo:3:006:4 -71 0
Feb 13 18:14:32 localhost cpcenter: f3c16140 3672674753 C Bi:3:006:4 -71 0
+3


source to share


1 answer


The string ^@^@^@^A

that is sent to your device is the result of an echo performed by the terminal subsystem in the kernel in response to incoming bytes from your device.

This line in your log:

Feb 13 18:14:32 localhost cpcenter: df046a80 3672670191 C Bi:3:006:4 0 4 = 00000001


actually means your device has sent 4 bytes to the computer ( Bi

stands for "Bulk endpoint, input"). By default, all terminal devices have echo resolution, so the kernel returns the bytes back to the device, but because these bytes are in the range of control characters, they are echoes in a shielded form: ^@^@^@^A

. Those echo bytes are also sent as separate 1-byte write calls, which corresponds to a 1-byte URB output in the subsequent log.

You need to fix your test program to disable echo and other tty processing before trying to communicate with your device. A function can be used for this cfmakeraw()

if your test program is in C / C ++.

A program can only run in Ubuntu because some other program touches the port in front of your test program and changes the port settings to disable echo.

+2


source






More articles:


All Articles