Устройство Linux cdc_acm — на устройство отправлены неожиданные символы

У меня возникают проблемы с отправкой неожиданных символов через USB-порт с помощью драйвера cdc_acm. Что делает это еще более запутанным, так это то, что код отлично работает на Ubuntu 12.04 (ядро 3.2), но терпит неудачу (предмет этого вопроса) на Centos 6 (ядро 3.6)

USB-устройство представляет собой Bluetooth Smart Dongle Bluegiga BLED112. Его встроенный микроконтроллер сбрасывается в любое время при неожиданном вводе данных через его USB-интерфейс.

Тестовый код открывает порт, записывает 4 байта (приветственное сообщение) и ожидает прочтения ответа. Чтение никогда не завершается, потому что неожиданные символы вызывают сброс устройства, что приводит к тому, что концентратор отбрасывает устройство и выполняет повторную нумерацию.

Чтобы устранить неполадки, вот что я сделал:

  • Скачал исходный код драйвера cdc_acm. Добавлено множество отладочных сообщений printk и stack_dumps, чтобы следить за тем, что происходит.
  • Я модифицировал "стандартный" cdc_acm и инмодулировал свой инструментальный модуль. Все перечисление устройств работает, правильный драйвер подключен и т.д.
  • Поскольку код работает на Ubuntu 12.04/Linux 3.2, я взял код 3.2 cdc_acm и скомпилировал этот модуль на платформе Centos 6/Linux 3.6. Использование этого модуля 3.2 вместо модуля 3.6 не имело значения. Я вернулся к модулю 3.6.
  • Включил отладочную файловую систему с помощью usbmon и посмотрел USB-трафик. Я вижу, что по интерфейсу USB отправляются дополнительные символы.
  • Чтобы посмотреть, что происходит, поверх printk в модуле cdc_acm я объединил вывод usb mon (cat /sys/kernel/debug/usb/usbmon/3u | logger) и вывод тестового приложения ( scan_example /dev/ttyACM0 | logger -s), поэтому у меня есть один поток коррелированного по времени отладочного следа.
  • Ложные символы, отправляемые на конечную точку USB, имеют вид x5E x40 x5E x40 x5E x40 x5E x40 x41 (в ASCII это ^@^@^@^@A), что выглядит как какое-то зондирование или попытка привлечь внимание модема Эти символы отправляются сразу после того, как приложение write() вызывает отправку 4 приветственных байтов в конечную точку.

  • Поскольку устройство cdc_acm должно быть модемом, я попытался отключить управление модемом, добавив его в usb_device_id acm_ids[] в cdc_acm.c.

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

  • Перекомпилирован и insmod'd, и системный журнал показывает, что это было распознано (причуды - 8), но никаких изменений в функции.

Ни NetowrkManager, ни модем-менеджер не запущены, но я все же подозреваю, что где-то происходит какая-то функция управления модемом, только не знаю где.

Вот аннотированный журнал отладки (MDV добавляет префиксы к тем printk, которые я добавил в 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

Вот 4 байта, отправленные приложением 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:

... и эти дополнительные символы появляются неожиданно 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 >

В этот момент мы получаем самопроизвольное отключение.

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

Трассировка стека во время отключения

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

linux cdc usb
person user2070305    schedule 14.02.2013    source источник

Ответы (1)


arrow_upward
6
arrow_downward

Строка ^@^@^@^A, отправляемая на ваше устройство, является результатом эха, выполняемого подсистемой терминала в ядре в ответ на входящие байты с вашего устройства.

Эта строка в вашем журнале:

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

на самом деле означает, что ваше устройство отправило 4 байта на компьютер (Bi означает «Массовая конечная точка, ввод»). По умолчанию на всех терминальных устройствах включено эхо, поэтому ядро ​​возвращает эти байты обратно на устройство, но, поскольку эти байты находятся в диапазоне управляющих символов, они отображаются в экранированной форме: ^@^@^@^A. Эти отраженные байты также отправляются отдельными вызовами записи по 1 байту, что соответствует 1-байтовым массовым URB в последующем журнале.

Вам нужно исправить свою тестовую программу, чтобы она отключала эхо и другую обработку tty, прежде чем пытаться связаться с вашим устройством. Для этого можно использовать функцию cfmakeraw(), если ваша тестовая программа написана на C/C++.

Программа может работать в Ubuntu только потому, что какая-то другая программа коснулась порта перед вашей тестовой программой и изменила настройки порта, чтобы отключить эхо.

person Sergey Vlasov    schedule 31.03.2013
comment
Анализ правильный и помог решить проблему. Глядя на трассировку ядра, он показывает localhost kernel: [<c12c6757>] process_echoes+0x117/0x2c0 localhost kernel: [<c12c8409>] n_tty_receive_char+0x379/0x770 localhost kernel: [<c121fce4>] ? rb_erase+0xb4/0x120 localhost kernel: [<c12c89f6>] n_tty_receive_buf+0x1f6/0x380 localhost kernel: [<c14d62cb>] ? __schedule+0x39b/0x6d0 - person user2070305; 18.04.2013
comment
Анализ правильный и помог решить проблему. Глядя на трассировку ядра, он показывает localhost kernel: [<c12c6757>] process_echoes+0x117/0x2c0 localhost kernel: [<c12c8409>] n_tty_receive_char+0x379/0x770 localhost kernel: [<c121fce4>] ? rb_erase+0xb4/0x120 localhost kernel: [<c12c89f6>] n_tty_receive_buf+0x1f6/0x380 localhost kernel: [<c14d62cb>] ? __schedule+0x39b/0x6d0, который показывает, что подсистема tty повторяет и стирает символы. Я добавил код, который использовал tcsetattr() из того же семейства, что и cfmakeraw(), чтобы удалить линейную дисциплину, и теперь он работает. - person user2070305; 18.04.2013
comment
У меня возникла та же проблема, но интересно то, что с тем же кабелем и устройством у меня возникла проблема на плате Olinuxino и не было проблем на моем обычном компьютере. Я полагаю, что эхо было установлено в обоих случаях (выход stty -a был одинаковым на обоих хостах). Поэтому я не стал его винить и прибегнул к анализу вывода usbmon, увидел там 5e40, погуглил и нашел вот этот гениальный вопрос :) - person ; 13.02.2014
comment
Тоже получил эту проблему. Раздражает, что такое универсальное последовательное устройство по умолчанию интерпретируется ОС как терминал. Но имейте в виду, что предоставленное решение не решает проблему полностью, потому что эхо должно быть отключено прежде чем какие-либо данные будут получены ядром с устройства. В противном случае это зависит от состояния гонки, как в моем случае. (Продолжение в следующем комментарии...) - person Artem Pisarenko; 24.06.2020
comment
(...продолжение) В моем случае устройство представляет собой специальное устройство CDC ACM, которое начинает отправлять данные на хост сразу после получения команды SetControlLineState с D0=1 (присутствует DTE), которая отправляется ядром/драйвером хоста при открытии хост-приложения. tty файловый дескриптор. Иногда у ядра/драйвера есть время, чтобы получить эти данные и отобразить их обратно до того, как приложение вызовет cfmakeraw()/tcsetattr(). Это приводит к тому, что устройство получает неожиданное дерьмо. Кроме того, это каким-то образом также искажает поток данных в направлении устройство-›хост. - person Artem Pisarenko; 24.06.2020