Linux: подключение флешки – mtp-probe bus: 2, device: 110 was not an MTP device и версия ядра

Автор: | 04/04/2018
 

Имеется новая флешка – Kingston DataTraveler SE9 (DTSE9H/32GB).

Ниже описаны попытки заставить систему её увидеть – и фееричная причина “проблемы”.

Проблема возникла на Arch Linux (причём на двух ноутбуках – рабочем, и домашнем), но не связана с дистрибутивом.

Суть проблемы

При подключении – флешка не монтируется, и в Dolphin не появляется:

Лог:

Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: new high-speed USB device number 110 using ehci-pci
Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: Product: DataTraveler 2.0
Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: Manufacturer: Kingston
Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: SerialNumber: 50E54951377FC160390C635E
Apr 04 20:29:58 setevoy-arch-home mtp-probe[29850]: checking bus 2, device 110: “/sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2”
Apr 04 20:29:58 setevoy-arch-home mtp-probe[29850]: bus: 2, device: 110 was not an MTP device
Apr 04 20:29:58 setevoy-arch-home upowerd[11980]: unhandled action ‘bind’ on /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2

Но само устройство USB видно:

[simterm]

$ lsusb | grep 110
Bus 002 Device 110: ID 0930:6544 Toshiba Corp. TransMemory-Mini / Kingston DataTraveler 2.0 Stick

[/simterm]

Так как в логе единственная ошибка связана с mtp-probe – то и первая мысль, что некорректно срабатывает сам mtp-probe, который входит в набор libmtp:

[simterm]

$ pacman -Ql libmtp | grep probe
libmtp /usr/lib/udev/mtp-probe

[/simterm]

Решение 1 – игнорировать mtp-probe

Сейчас не могу найти обсуждение, где нашёл этот вариант – но некоторым, вроде, помогает (хотя не в этом случае, см. далее)

Правила определения устройств описываются в файлах в каталоге /lib/udev/rules.d/, где libmtp создаёт файл 69-libmtp.rules, в конце которого вызывается mtp-probe, если устройство не найдено в правилах в этом файле выше:

...
# Autoprobe vendor-specific, communication and PTP devices
ENV{ID_MTP_DEVICE}!="1", ENV{MTP_NO_PROBE}!="1", ENV{COLOR_MEASUREMENT_DEVICE}!="1", ENV{libsane_matched}!="yes", ATTR{bDeviceClass}=="00|02|06|ef|ff", PROGRAM="/usr/lib/udev/mtp-probe /sys$env{DEVPATH} $attr{busnum} $attr{devnum}", RESULT=="1", SYMLINK+="libmtp-%k", ENV{ID_MTP_DEVICE}="1", ENV{ID_MEDIA_PLAYER}="1"
...

Попробуем добавить условие, что бы при обнаружении этой флешки – libmtp пропускал его, и ядро само начинало монтировать флешку.

Копируем /lib/udev/rules.d/69-libmtp.rules в /etc/udev/rules.d/ (если внести изменения в /lib/udev/rules.d/69-libmtp.rules – они перезапишутся при следующем обновлении пакета libmtp):

[simterm]

$ sudo cp /lib/udev/rules.d/69-libmtp.rules /etc/udev/rules.d/

[/simterm]

Находим ID вендора и устройства.

Ещё раз смотрим вывод lsusb:

[simterm]

$ lsusb | grep 110
Bus 002 Device 110: ID 0930:6544 Toshiba Corp. TransMemory-Mini / Kingston DataTraveler 2.0 Stick

[/simterm]

Шина 002, устройство 110.

Теперь используем udevadm info, указав путь к устройству:

[simterm]

$ udevadm info -a -n /dev/bus/usb/002/110 | grep 'idProduct\|idVendor' | head -2
    ATTR{idProduct}=="6544"
    ATTR{idVendor}=="0930"

[/simterm]

Другой вариант – посмотреть dmesg:

[simterm]

$ dmesg | tail | grep usb
[650426.609113] usb 2-1.2: Product: DataTraveler 2.0
[650426.609115] usb 2-1.2: Manufacturer: Kingston
[650426.609117] usb 2-1.2: SerialNumber: 50E54951377FC160390C635E
[650472.436525] usb 2-1.2: USB disconnect, device number 109
[650475.936558] usb 2-1.2: new high-speed USB device number 110 using ehci-pci
[650476.017379] usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
[650476.017383] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[650476.017385] usb 2-1.2: Product: DataTraveler 2.0
[650476.017387] usb 2-1.2: Manufacturer: Kingston
[650476.017389] usb 2-1.2: SerialNumber: 50E54951377FC160390C635E

[/simterm]

Ну и в выводе journalctl ID тоже указываются:

Apr 04 20:29:58 setevoy-arch-home kernel: usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544

Обновляем /etc/udev/rules.d/69-libmtp.rules, и в начале файла, после других GOTO="libmtp_rules_end", добавляем условие “для вендора с ID 0930 и устройства с ID 6544” и действие “пропустить все правила, и перейти сразу к концу файла правил“:

...
# added by setevoy - skip Kingston flash drive
ATTR{idVendor}=="0930", ATTR{idProduct}=="6544", GOTO="libmtp_rules_end"
...

Сохраняем, переподключаем флешку, проверям journalctl:

Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: new high-speed USB device number 112 using ehci-pci
Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: Product: DataTraveler 2.0
Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: Manufacturer: Kingston
Apr 04 20:40:30 setevoy-arch-home kernel: usb 2-1.2: SerialNumber: 50E54951377FC160390C635E
Apr 04 20:40:31 setevoy-arch-home upowerd[11980]: unhandled action ‘bind’ on /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2

ОК, флешку видит, ошибки mpt-probe теперь нет, но не монтирует – не создаётся устройство /dev/sdb:

[simterm]

$ lsblk 
NAME                       MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
loop0                        7:0    0   100G  0 loop 
└─docker-254:0-155755-pool 254:2    0   100G  0 dm   
loop1                        7:1    0     2G  0 loop 
└─docker-254:0-155755-pool 254:2    0   100G  0 dm   
sda                          8:0    0 465.8G  0 disk 
├─sda1                       8:1    0     2G  0 part /boot
├─sda2                       8:2    0    16G  0 part [SWAP]
└─sda3                       8:3    0 447.8G  0 part 
  ├─vg_arch-root           254:0    0  47.8G  0 lvm  /
  └─vg_arch-home           254:1    0   400G  0 lvm  /home
sr0                         11:0    1  1024M  0 rom

[/simterm]

Проверяем dmesg – тут тоже ничего:

[simterm]

[Mar24 22:28] usb 2-1.2: new high-speed USB device number 112 using ehci-pci
[  +0.080781] usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
[  +0.000006] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  +0.000003] usb 2-1.2: Product: DataTraveler 2.0
[  +0.000003] usb 2-1.2: Manufacturer: Kingston
[  +0.000003] usb 2-1.2: SerialNumber: 50E54951377FC160390C635E

[/simterm]

Интересно, почему дата в dmesg неправильная – но тут ответ нашёлся в man dmesg:

-T, –ctime
Print human-readable timestamps.

Be aware that the timestamp could be inaccurate! The time source used for the logs is not updated after system SUSPEND/RESUME.

Драйвер usb-storage

Тут пришлось немного почитать про USB subsystem в Linux вообще – довольно интересно.

Несколько полезных ссылок:

И где вызов usb-storage, и где создание устройства в /dev?

ОК, проверяем наличие драйвера usb-storage:

[simterm]

# lsmod | grep usb
btusb                  53248  0
btrtl                  16384  1 btusb
btbcm                  16384  1 btusb
btintel                16384  1 btusb
bluetooth             634880  5 btrtl,btintel,btbcm,btusb
usbhid                 57344  0
hid                   131072  4 hid_generic,usbhid,hid_logitech_dj,hid_logitech_hidpp
usbcore               286720  5 uvcvideo,usbhid,ehci_hcd,btusb,ehci_pci
usb_common             16384  1 usbcore

[/simterm]

usb-storage нет… Хотя файл драйвера – есть:

[simterm]

# find /lib/modules -name usb-storage*
/lib/modules/4.15.14-1-ARCH/kernel/drivers/usb/storage/usb-storage.ko.xz

[/simterm]

Или в выводе самого modprobe:

[simterm]

$ modinfo usb-storage | grep file
filename:       /lib/modules/4.15.14-1-ARCH/kernel/drivers/usb/storage/usb-storage.ko.xz

[/simterm]

Тут я ещё пробовал добавить правило для udev:

$ cat /etc/udev/rules.d/90-king.rules 
SUBSYSTEM=="usb", ATTR{idVendor}=="0930", ATTR{idProduct}=="6544", ENV{MODALIAS}="usb-storage"

Но это не помогло, потому останавливаться на этом не буду.

True “решение”

А теперь – внимание.

Обращаем внимание на путь к файлу драйвера – /lib/modules/4.15.14-1-ARCH/kernel/drivers/usb/storage/usb-storage.ko.xz, и проверяем текущую загруженную версию ядра:

[simterm]

# uname -r
4.15.9-1-ARCH

[/simterm]

4.15.14-1-ARCH и 4.15.9-1-ARCH.

Первая мысль – “Да ладно, б***??? Всё оказалось так просто?”…

Систему я обновляю регулярно, каждую неделю, а вот перезагружать ноутбук – не хочется, ибо вкладки в браузере и вообще…

В результате, получаем ситуацию, когда файл ищется по пути текущей версии ядра – 4.15.9-1-ARCH, а расположен в каталоге /lib/modules/4.15.14-1-ARCH

Удвило, что о проблеме с загрузкой драйвера никаких сообщений в логах.

Хорошо – пробуем загрузить модуль вручную, и только теперь увидим ошибку:

[simterm]

# modprobe usb-storage
modprobe: FATAL: Module usb-storage not found in directory /lib/modules/4.15.9-1-ARCH

[/simterm]

В man modprobe даже указывается – как именно он ищет файлы:

DESCRIPTION
modprobe intelligently adds or removes a module from the Linux kernel: note that for convenience, there is no difference between _ and – in module names (automatic underscore conversion is performed).  modprobe looks in the
module directory /lib/modules/`uname -r` for all the modules and other files […]

Можно было бы попробовать добавить модуль с помощью insmod (который и вызывается modprobe) – но и тут ошибки:

[simterm]

# insmod /lib/modules/4.15.14-1-ARCH/kernel/drivers/usb/storage/usb-storage.ko.xz
insmod: ERROR: could not insert module /lib/modules/4.15.14-1-ARCH/kernel/drivers/usb/storage/usb-storage.ko.xz: Invalid parameters

[/simterm]

И в dmesg:

[simterm]

[Mar24 22:50] usb_storage: disagrees about version of symbol scsi_report_device_reset
[  +0.000004] usb_storage: Unknown symbol scsi_report_device_reset (err -22)
[  +0.000177] usb_storage: disagrees about version of symbol scsi_remove_host
[  +0.000002] usb_storage: Unknown symbol scsi_remove_host (err -22)
[  +0.000090] usb_storage: disagrees about version of symbol scsi_report_bus_reset
[  +0.000002] usb_storage: Unknown symbol scsi_report_bus_reset (err -22)
[  +0.000222] usb_storage: disagrees about version of symbol scsi_eh_prep_cmnd
[  +0.000002] usb_storage: Unknown symbol scsi_eh_prep_cmnd (err -22)
[  +0.000264] usb_storage: disagrees about version of symbol scsi_host_put
[  +0.000003] usb_storage: Unknown symbol scsi_host_put (err -22)
[  +0.000089] usb_storage: disagrees about version of symbol scsi_scan_host
[  +0.000002] usb_storage: Unknown symbol scsi_scan_host (err -22)
[  +0.000220] usb_storage: disagrees about version of symbol scsi_eh_restore_cmnd
[  +0.000002] usb_storage: Unknown symbol scsi_eh_restore_cmnd (err -22)
[  +0.000089] usb_storage: disagrees about version of symbol scsi_cmd_get_serial
[  +0.000002] usb_storage: Unknown symbol scsi_cmd_get_serial (err -22)
[  +0.000134] usb_storage: disagrees about version of symbol scsi_add_host_with_dma
[  +0.000002] usb_storage: Unknown symbol scsi_add_host_with_dma (err -22)
[  +0.000122] usb_storage: disagrees about version of symbol scsi_host_alloc
[  +0.000002] usb_storage: Unknown symbol scsi_host_alloc (err -22)
[  +0.000076] usb_storage: disagrees about version of symbol scsi_get_host_dev
[  +0.000002] usb_storage: Unknown symbol scsi_get_host_dev (err -22)

[/simterm]

Собственно, решение – перезагрузить систему, что бы применить новое ядро и каталог поиска драйверов:

[simterm]

# reboot

[/simterm]

Подключаем флешку, проверяем вывод dmesg:

[simterm]

$ dmesg -wH
...
[Apr 4 21:14] usb 2-1.2: new high-speed USB device number 7 using ehci-pci
[  +0.081317] usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
[  +0.000019] usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  +0.000004] usb 2-1.2: Product: DataTraveler 2.0
[  +0.000005] usb 2-1.2: Manufacturer: Kingston
[  +0.000004] usb 2-1.2: SerialNumber: 50E54951377FC160390C635E
[  +0.077525] usb-storage 2-1.2:1.0: USB Mass Storage device detected
[  +0.001201] scsi host6: usb-storage 2-1.2:1.0
[  +0.000236] usbcore: registered new interface driver usb-storage
[  +0.012368] usbcore: registered new interface driver uas
[  +1.044857] scsi 6:0:0:0: Direct-Access     Kingston DataTraveler 2.0 1.00 PQ: 0 ANSI: 4
[  +0.001703] sd 6:0:0:0: [sdb] 60620800 512-byte logical blocks: (31.0 GB/28.9 GiB)
[  +0.000687] sd 6:0:0:0: [sdb] Write Protect is off
[  +0.000003] sd 6:0:0:0: [sdb] Mode Sense: 45 00 00 00
[  +0.000624] sd 6:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[  +0.004554]  sdb: sdb1
[  +0.002579] sd 6:0:0:0: [sdb] Attached SCSI removable disk

[/simterm]

Логи:

Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: new high-speed USB device number 7 using ehci-pci
Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: New USB device found, idVendor=0930, idProduct=6544
Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: Product: DataTraveler 2.0
Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: Manufacturer: Kingston
Apr 04 21:14:42 setevoy-arch-home kernel: usb 2-1.2: SerialNumber: 50E54951377FC160390C635E
Apr 04 21:14:42 setevoy-arch-home kernel: usb-storage 2-1.2:1.0: USB Mass Storage device detected
Apr 04 21:14:42 setevoy-arch-home kernel: scsi host6: usb-storage 2-1.2:1.0
Apr 04 21:14:42 setevoy-arch-home kernel: usbcore: registered new interface driver usb-storage
Apr 04 21:14:42 setevoy-arch-home kernel: usbcore: registered new interface driver uas
Apr 04 21:14:42 setevoy-arch-home upowerd[4262]: unhandled action ‘bind’ on /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2
Apr 04 21:14:42 setevoy-arch-home upowerd[4262]: unhandled action ‘bind’ on /sys/devices/pci0000:00/0000:00:1d.0/usb2/2-1/2-1.2/2-1.2:1.0
Apr 04 21:14:43 setevoy-arch-home kernel: scsi 6:0:0:0: Direct-Access     Kingston DataTraveler 2.0 1.00 PQ: 0 ANSI: 4
Apr 04 21:14:43 setevoy-arch-home kernel: sd 6:0:0:0: [sdb] 60620800 512-byte logical blocks: (31.0 GB/28.9 GiB)
Apr 04 21:14:43 setevoy-arch-home kernel: sd 6:0:0:0: [sdb] Write Protect is off
Apr 04 21:14:43 setevoy-arch-home kernel: sd 6:0:0:0: [sdb] Mode Sense: 45 00 00 00
Apr 04 21:14:43 setevoy-arch-home kernel: sd 6:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn’t support DPO or FUA
Apr 04 21:14:43 setevoy-arch-home kernel:  sdb: sdb1
Apr 04 21:14:43 setevoy-arch-home kernel: sd 6:0:0:0: [sdb] Attached SCSI removable disk

Находим драйвер:

[simterm]

$ lsmod | grep usb_storage
usb_storage            73728  1 uas
scsi_mod              258048  5 sd_mod,usb_storage,libata,uas,sr_mod
usbcore               286720  7 uvcvideo,usbhid,usb_storage,ehci_hcd,btusb,uas,ehci_pci

[/simterm]

Всё на месте.

Флешка в выводе lsusb:

[simterm]

$ lsusb | grep King
Bus 002 Device 007: ID 0930:6544 Toshiba Corp. TransMemory-Mini / Kingston DataTraveler 2.0 Stick

[/simterm]

И проверяем драйвер шины 2, устройства 007:

[simterm]

$ lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M
        |__ Port 1: Dev 3, If 2, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 1: Dev 3, If 0, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 1: Dev 3, If 1, Class=Human Interface Device, Driver=usbhid, 12M
        |__ Port 2: Dev 7, If 0, Class=Mass Storage, Driver=usb-storage, 480M
...

[/simterm]

Driver=usb-storage – всё нашлось.

Флешка в Dolphin:

И в lsblk:

[simterm]

$ lsblk 
NAME                MAJ:MIN RM   SIZE RO TYPE MOUNTPOINT
sda                   8:0    0 596.2G  0 disk 
├─sda1                8:1    0     2G  0 part 
├─sda2                8:2    0    16G  0 part 
├─sda3                8:3    0   500G  0 part 
│ ├─kubuntu_vg-root 254:0    0    30G  0 lvm  /
│ └─kubuntu_vg-home 254:1    0   470G  0 lvm  /home
└─sda4                8:4    0  78.2G  0 part /media/winold
sdb                   8:16   1  28.9G  0 disk 
└─sdb1                8:17   1  28.9G  0 part /run/media/setevoy/KINGSTON

 

[/simterm]

Такие дела.

Но было интересно 🙂