Skip to content

Instantly share code, notes, and snippets.

@Julio-Guerra

Julio-Guerra/bug.sh

Created August 20, 2016 03:11
Show Gist options
  • Save Julio-Guerra/b6529994f814771c825649bdb8d927c2 to your computer and use it in GitHub Desktop.
Save Julio-Guerra/b6529994f814771c825649bdb8d927c2 to your computer and use it in GitHub Desktop.
Download ZIP
cdc_acm buffer read problem
Raw
bug.sh
#!/bin/bash
set -e
: ${1?"missing argument 1: device node (e.g. /dev/ttyAMC0)"}
dev=$1
stty -F $dev 9600 raw min 8
# open the device once, with file descriptor 4
exec 4<>$dev
# necessart sleep to avoid device problems
function cooldown() {
sleep 0.04
}
function dump() {
hexdump -C
# newline
echo
}
function state() {
# state request
echo -ne "\xFF\x09\x00" >&4
cooldown
# read the answer: exactly 8 bytes
# dd is used because it does not change the tty settings and
# does not expect only ascii.
dd bs=1 count=8 <&4 2>&- | dump
cooldown
}
while true; do
state
done
# close the file descriptor
exec 4>&-
@Julio-Guerra
Copy link
Author

Running this with dynamic debugs enabled.

Pluging the device:

[ +13.847898] usb 2-2.3: new full-speed USB device number 14 using uhci_hcd
[  +0.186117] cdc_acm 2-2.3:1.0: The data interface has switched endpoints
[  +0.000012] cdc_acm 2-2.3:1.0: interfaces are valid
[  +0.010795] cdc_acm 2-2.3:1.0: ttyACM0: USB ACM device
[  +0.002060] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x20, val 0x0, len 0x7, result 7

Changing the device state to observe the bug in an answer to a state request:

[Sep16 18:16] tty ttyACM0: acm_tty_install
[  +0.000010] tty ttyACM0: acm_tty_open
[  +0.000003] cdc_acm 2-2.3:1.0: acm_port_activate
[  +0.170383] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  +0.050375] cdc_acm 2-2.3:1.0: acm_tty_close
[  +0.000843] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result 0
[  +0.000005] cdc_acm 2-2.3:1.0: acm_port_shutdown
[  +0.000761] cdc_acm 2-2.3:1.0: acm_ctrl_irq - urb shutting down with status: -2
[  +0.011768] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001169] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001187] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001256] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001289] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.009520] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.009993] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001187] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001300] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001315] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.010477] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.009487] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.010289] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001212] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001089] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001121] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000070] tty ttyACM0: acm_tty_install
[  +0.000007] tty ttyACM0: acm_tty_open
[  +0.000002] cdc_acm 2-2.3:1.0: acm_port_activate
[  +0.000032] cdc_acm 2-2.3:1.0: acm_tty_cleanup
[  +0.010342] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  +0.030926] cdc_acm 2-2.3:1.0: acm_tty_close
[  +0.001738] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result 0
[  +0.000005] cdc_acm 2-2.3:1.0: acm_port_shutdown
[  +0.000600] cdc_acm 2-2.3:1.0: acm_ctrl_irq - urb shutting down with status: -2
[  +0.001166] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000999] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.010034] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.019907] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.010110] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001234] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001232] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001251] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.010528] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001344] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001203] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.009893] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000966] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001144] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001118] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001210] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000102] cdc_acm 2-2.3:1.0: acm_tty_cleanup

Running the script:

[ +41.256318] tty ttyACM0: acm_tty_install
[  +0.000010] tty ttyACM0: acm_tty_open
[  +0.000003] cdc_acm 2-2.3:1.0: acm_port_activate
[  +0.031268] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0
[  +0.000963] cdc_acm 2-2.3:1.0: acm_tty_close
[  +0.001714] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result 0
[  +0.000012] cdc_acm 2-2.3:1.0: acm_port_shutdown
[  +0.000243] cdc_acm 2-2.3:1.0: acm_ctrl_irq - urb shutting down with status: -2
[  +0.014527] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001004] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001114] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001371] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001216] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001246] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001210] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001352] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001501] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.002657] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000888] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.003286] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001271] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.011385] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001062] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001194] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000127] cdc_acm 2-2.3:1.0: acm_tty_cleanup
[  +0.000339] tty ttyACM0: acm_tty_install
[  +0.000027] tty ttyACM0: acm_tty_open
[  +0.000009] cdc_acm 2-2.3:1.0: acm_port_activate
[  +0.038709] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x3, len 0x0, result 0

Stopping the script once the bug observed:

[Sep16 18:17] cdc_acm 2-2.3:1.0: acm_tty_close
[  +0.000960] cdc_acm 2-2.3:1.0: acm_ctrl_msg - rq 0x22, val 0x0, len 0x0, result 0
[  +0.000007] cdc_acm 2-2.3:1.0: acm_port_shutdown
[  +0.000606] cdc_acm 2-2.3:1.0: acm_ctrl_irq - urb shutting down with status: -2
[  +0.001259] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.011773] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.018266] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001111] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001234] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.001243] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.023371] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000656] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000434] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000757] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000322] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000878] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000221] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.011356] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.002111] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.002802] cdc_acm 2-2.3:1.1: acm_read_bulk_callback - non-zero urb status: -2
[  +0.000721] cdc_acm 2-2.3:1.0: acm_tty_cleanup

Script output (dump of a request result, observe the 01 shift):

00000000  00 01 00 00 00 00 00 00                           |........|
00000008

00000000  00 01 00 00 00 00 00 00                           |........|
00000008

00000000  00 01 00 00 00 00 00 00                           |........|
00000008
===== problem appears now =====
00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

00000000  00 00 01 00 00 00 00 00                           |........|
00000008

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment