May 2 12:05:15 marius-T1005 kernel: [18791.997154] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
May 2 12:05:31 marius-T1005 kernel: [18807.996898] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:05:41 marius-T1005 udevd[9591]: timeout 'cdrom_id --lock-media /dev/sr0'
May 2 12:05:42 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:06:13 udevd[9591]: last message repeated 31 times
May 2 12:06:23 udevd[9591]: last message repeated 10 times
May 2 12:06:23 marius-T1005 kernel: [18859.997078] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:06:23 marius-T1005 kernel: [18860.000567] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
May 2 12:06:24 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:07:15 udevd[9591]: last message repeated 51 times
May 2 12:07:15 marius-T1005 kernel: [18911.997026] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:07:16 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:08:06 udevd[9591]: last message repeated 50 times
May 2 12:08:06 marius-T1005 kernel: [18963.080268] INFO: task usb_modeswitch:17507 blocked for more than 120 seconds.
May 2 12:08:06 marius-T1005 kernel: [18963.080281] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
...
May 2 12:08:06 marius-T1005 kernel: [18963.080292] usb_modeswitch D 00070509 0 17507 17470 0x00000000
May 2 12:08:06 marius-T1005 kernel: [18963.080310] c323dc80 00200086 c1069cdd 00070509 00000000 ffffffff c18f2380 c18f2380
May 2 12:08:06 marius-T1005 kernel: [18963.080340] c18f2380 c18f2380 7a6ecefc 00001110 c18f2380 f7007380 f2f23f20 f3ec3f20
May 2 12:08:06 marius-T1005 kernel: [18963.080366] f71073c4 006dd89d f71073ec dd51cbc0 00001110 00000000 00000001 c323dc78
May 2 12:08:06 marius-T1005 kernel: [18963.080393] Call Trace:
May 2 12:08:06 marius-T1005 kernel: [18963.080417] [<c1069cdd>] ? update_curr+0x24d/0x2a0
May 2 12:08:06 marius-T1005 kernel: [18963.080435] [<c106a530>] ? check_preempt_wakeup+0x140/0x220
May 2 12:08:06 marius-T1005 kernel: [18963.080451] [<c157d303>] schedule+0x23/0x60
May 2 12:08:06 marius-T1005 kernel: [18963.080465] [<c157b85d>] schedule_timeout+0x19d/0x260
May 2 12:08:06 marius-T1005 kernel: [18963.080480] [<c105d7ca>] ? check_preempt_curr+0x6a/0x80
May 2 12:08:06 marius-T1005 kernel: [18963.080493] [<c1062b30>] ? ttwu_do_wakeup+0x30/0x110
May 2 12:08:06 marius-T1005 kernel: [18963.080506] [<c1065e6e>] ? try_to_wake_up+0x1ce/0x230
May 2 12:08:06 marius-T1005 kernel: [18963.080520] [<c157d188>] wait_for_common+0xa8/0x120
May 2 12:08:06 marius-T1005 kernel: [18963.080533] [<c1065ed0>] ? try_to_wake_up+0x230/0x230
May 2 12:08:06 marius-T1005 kernel: [18963.080547] [<c157d2d7>] wait_for_completion+0x17/0x20
May 2 12:08:06 marius-T1005 kernel: [18963.080562] [<c104eefd>] wait_on_work+0x14d/0x160
May 2 12:08:06 marius-T1005 kernel: [18963.080575] [<c104d460>] ? do_work_for_cpu+0x20/0x20
May 2 12:08:06 marius-T1005 kernel: [18963.080589] [<c104efd9>] __cancel_work_timer+0x39/0x120
May 2 12:08:06 marius-T1005 kernel: [18963.080604] [<c104f0d0>] cancel_delayed_work_sync+0x10/0x20
May 2 12:08:06 marius-T1005 kernel: [18963.080618] [<c128f5de>] disk_block_events+0x7e/0x80
May 2 12:08:06 marius-T1005 kernel: [18963.080630] [<c1290657>] del_gendisk+0x27/0x1a0
May 2 12:08:06 marius-T1005 kernel: [18963.080644] [<c13b288b>] sr_remove+0x2b/0x60
May 2 12:08:06 marius-T1005 kernel: [18963.080658] [<c1375f2b>] __device_release_driver+0x5b/0xb0
[18963.080671] [<c1376045>] device_release_driver+0x25/0x40
[18963.080684] [<c1375363>] bus_remove_device+0xc3/0xf0
[18963.080697] [<c13737c5>] device_del+0xe5/0x180
[18963.080711] [<c13a7831>] __scsi_remove_device+0xa1/0xb0
[18963.080724] [<c13a4357>] scsi_forget_host+0x57/0x60
[18963.080738] [<c139cb9d>] scsi_remove_host+0x5d/0xf0
[18963.080759] [<f90c810d>] quiesce_and_remove_host+0x4d/0xc0 [usb_storage]
[18963.080778] [<f90c8238>] usb_stor_disconnect+0x18/0x30 [usb_storage]
[18963.080793] [<c13fad10>] usb_unbind_interface+0x40/0x150
[18963.080807] [<c1375f2b>] __device_release_driver+0x5b/0xb0
[18963.080820] [<c1376045>] device_release_driver+0x25/0x40
[18963.080833] [<c13fb057>] usb_driver_release_interface+0x77/0x80
[18963.080848] [<c1401075>] proc_ioctl+0x175/0x180
[18963.080861] [<c14013cb>] usbdev_do_ioctl+0x34b/0xa60
[18963.080876] [<c110fbfa>] ? handle_mm_fault+0xfa/0x220
[18963.080891] [<c1401ae0>] ? usbdev_do_ioctl+0xa60/0xa60
[18963.080905] [<c1401aed>] usbdev_ioctl+0xd/0x10
[18963.080918] [<c114b5a6>] do_vfs_ioctl+0x86/0x2d0
[18963.080931] [<c114b867>] sys_ioctl+0x77/0x80
[18963.080944] [<c1584e9f>] sysenter_do_call+0x12/0x28
[18963.996973] sr 4:0:0:0: Device offlined - not ready after error recovery
Eject does not work. Either timeout or the device does not exists. It seems that these extensive stacktraces does not appear at every insertion of the modem, but it still does not work.
When connecting it to the USB 2.0 port, there is no such errors:
[22619.549611] scsi5 : usb-storage 1-1:1.0
[22620.550036] scsi 5:0:0:0: CD-ROM ZTE USB SCSI CD-ROM 2.31 PQ: 0 ANSI: 0
[22620.558739] sr0: scsi-1 drive
[22620.559380] sr 5:0:0:0: Attached scsi CD-ROM sr0
[22620.559970] sr 5:0:0:0: Attached scsi generic sg1 type 5
[22627.100137] usb 1-1: reset high-speed USB device number 10 using ehci_hcd
[22628.183131] usb 1-1: USB disconnect, device number 10
[22633.200131] usb 1-1: new high-speed USB device number 11 using ehci_hcd
[22633.439744] usbcore: registered new interface driver usbserial
[22633.439835] usbcore: registered new interface driver usbserial_generic
[22633.439912] USB Serial support registered for generic
[22633.440736] usbserial: USB Serial Driver core
[22633.530364] usbcore: registered new interface driver option
[22633.530445] USB Serial support registered for GSM modem (1-port)
[22633.531143] option 1-1:1.0: GSM modem (1-port) converter detected
[22633.531938] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
[22633.532157] option 1-1:1.1: GSM modem (1-port) converter detected
[22633.532500] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
[22633.532749] option 1-1:1.2: GSM modem (1-port) converter detected
[22633.533045] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
[22633.533152] option 1-1:1.3: GSM modem (1-port) converter detected
[22633.533507] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB3
Can we then conclude that this is probably a Linux kernel issue?
May 2 12:05:15 marius-T1005 kernel: [18791.997154] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD 17507 blocked for more than 120 seconds. kernel/ hung_task_ timeout_ secs" disables this message. curr+0x24d/ 0x2a0 wakeup+ 0x140/0x220 timeout+ 0x19d/0x260 curr+0x6a/ 0x80 wakeup+ 0x30/0x110 wake_up+ 0x1ce/0x230 common+ 0xa8/0x120 wake_up+ 0x230/0x230 completion+ 0x17/0x20 work+0x14d/ 0x160 for_cpu+ 0x20/0x20 work_timer+ 0x39/0x120 delayed_ work_sync+ 0x10/0x20 events+ 0x7e/0x80 0x27/0x1a0 release_ driver+ 0x5b/0xb0 release_ driver+ 0x25/0x40 device+ 0xc3/0xf0 del+0xe5/ 0x180 remove_ device+ 0xa1/0xb0 host+0x57/ 0x60 host+0x5d/ 0xf0 and_remove_ host+0x4d/ 0xc0 [usb_storage] disconnect+ 0x18/0x30 [usb_storage] interface+ 0x40/0x150 release_ driver+ 0x5b/0xb0 release_ driver+ 0x25/0x40 release_ interface+ 0x77/0x80 0x175/0x180 do_ioctl+ 0x34b/0xa60 mm_fault+ 0xfa/0x220 do_ioctl+ 0xa60/0xa60 ioctl+0xd/ 0x10 ioctl+0x86/ 0x2d0 do_call+ 0x12/0x28
May 2 12:05:31 marius-T1005 kernel: [18807.996898] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:05:41 marius-T1005 udevd[9591]: timeout 'cdrom_id --lock-media /dev/sr0'
May 2 12:05:42 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:06:13 udevd[9591]: last message repeated 31 times
May 2 12:06:23 udevd[9591]: last message repeated 10 times
May 2 12:06:23 marius-T1005 kernel: [18859.997078] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:06:23 marius-T1005 kernel: [18860.000567] xhci_hcd 0000:02:00.0: ERROR Transfer event TRB DMA ptr not part of current TD
May 2 12:06:24 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:07:15 udevd[9591]: last message repeated 51 times
May 2 12:07:15 marius-T1005 kernel: [18911.997026] sr 4:0:0:0: Device offlined - not ready after error recovery
May 2 12:07:16 marius-T1005 udevd[9591]: timeout: killing 'cdrom_id --lock-media /dev/sr0' [17485]
May 2 12:08:06 udevd[9591]: last message repeated 50 times
May 2 12:08:06 marius-T1005 kernel: [18963.080268] INFO: task usb_modeswitch:
May 2 12:08:06 marius-T1005 kernel: [18963.080281] "echo 0 > /proc/sys/
...
May 2 12:08:06 marius-T1005 kernel: [18963.080292] usb_modeswitch D 00070509 0 17507 17470 0x00000000
May 2 12:08:06 marius-T1005 kernel: [18963.080310] c323dc80 00200086 c1069cdd 00070509 00000000 ffffffff c18f2380 c18f2380
May 2 12:08:06 marius-T1005 kernel: [18963.080340] c18f2380 c18f2380 7a6ecefc 00001110 c18f2380 f7007380 f2f23f20 f3ec3f20
May 2 12:08:06 marius-T1005 kernel: [18963.080366] f71073c4 006dd89d f71073ec dd51cbc0 00001110 00000000 00000001 c323dc78
May 2 12:08:06 marius-T1005 kernel: [18963.080393] Call Trace:
May 2 12:08:06 marius-T1005 kernel: [18963.080417] [<c1069cdd>] ? update_
May 2 12:08:06 marius-T1005 kernel: [18963.080435] [<c106a530>] ? check_preempt_
May 2 12:08:06 marius-T1005 kernel: [18963.080451] [<c157d303>] schedule+0x23/0x60
May 2 12:08:06 marius-T1005 kernel: [18963.080465] [<c157b85d>] schedule_
May 2 12:08:06 marius-T1005 kernel: [18963.080480] [<c105d7ca>] ? check_preempt_
May 2 12:08:06 marius-T1005 kernel: [18963.080493] [<c1062b30>] ? ttwu_do_
May 2 12:08:06 marius-T1005 kernel: [18963.080506] [<c1065e6e>] ? try_to_
May 2 12:08:06 marius-T1005 kernel: [18963.080520] [<c157d188>] wait_for_
May 2 12:08:06 marius-T1005 kernel: [18963.080533] [<c1065ed0>] ? try_to_
May 2 12:08:06 marius-T1005 kernel: [18963.080547] [<c157d2d7>] wait_for_
May 2 12:08:06 marius-T1005 kernel: [18963.080562] [<c104eefd>] wait_on_
May 2 12:08:06 marius-T1005 kernel: [18963.080575] [<c104d460>] ? do_work_
May 2 12:08:06 marius-T1005 kernel: [18963.080589] [<c104efd9>] __cancel_
May 2 12:08:06 marius-T1005 kernel: [18963.080604] [<c104f0d0>] cancel_
May 2 12:08:06 marius-T1005 kernel: [18963.080618] [<c128f5de>] disk_block_
May 2 12:08:06 marius-T1005 kernel: [18963.080630] [<c1290657>] del_gendisk+
May 2 12:08:06 marius-T1005 kernel: [18963.080644] [<c13b288b>] sr_remove+0x2b/0x60
May 2 12:08:06 marius-T1005 kernel: [18963.080658] [<c1375f2b>] __device_
[18963.080671] [<c1376045>] device_
[18963.080684] [<c1375363>] bus_remove_
[18963.080697] [<c13737c5>] device_
[18963.080711] [<c13a7831>] __scsi_
[18963.080724] [<c13a4357>] scsi_forget_
[18963.080738] [<c139cb9d>] scsi_remove_
[18963.080759] [<f90c810d>] quiesce_
[18963.080778] [<f90c8238>] usb_stor_
[18963.080793] [<c13fad10>] usb_unbind_
[18963.080807] [<c1375f2b>] __device_
[18963.080820] [<c1376045>] device_
[18963.080833] [<c13fb057>] usb_driver_
[18963.080848] [<c1401075>] proc_ioctl+
[18963.080861] [<c14013cb>] usbdev_
[18963.080876] [<c110fbfa>] ? handle_
[18963.080891] [<c1401ae0>] ? usbdev_
[18963.080905] [<c1401aed>] usbdev_
[18963.080918] [<c114b5a6>] do_vfs_
[18963.080931] [<c114b867>] sys_ioctl+0x77/0x80
[18963.080944] [<c1584e9f>] sysenter_
[18963.996973] sr 4:0:0:0: Device offlined - not ready after error recovery
Eject does not work. Either timeout or the device does not exists. It seems that these extensive stacktraces does not appear at every insertion of the modem, but it still does not work.
When connecting it to the USB 2.0 port, there is no such errors:
[22619.549611] scsi5 : usb-storage 1-1:1.0
[22620.550036] scsi 5:0:0:0: CD-ROM ZTE USB SCSI CD-ROM 2.31 PQ: 0 ANSI: 0
[22620.558739] sr0: scsi-1 drive
[22620.559380] sr 5:0:0:0: Attached scsi CD-ROM sr0
[22620.559970] sr 5:0:0:0: Attached scsi generic sg1 type 5
[22627.100137] usb 1-1: reset high-speed USB device number 10 using ehci_hcd
[22628.183131] usb 1-1: USB disconnect, device number 10
[22633.200131] usb 1-1: new high-speed USB device number 11 using ehci_hcd
[22633.439744] usbcore: registered new interface driver usbserial
[22633.439835] usbcore: registered new interface driver usbserial_generic
[22633.439912] USB Serial support registered for generic
[22633.440736] usbserial: USB Serial Driver core
[22633.530364] usbcore: registered new interface driver option
[22633.530445] USB Serial support registered for GSM modem (1-port)
[22633.531143] option 1-1:1.0: GSM modem (1-port) converter detected
[22633.531938] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB0
[22633.532157] option 1-1:1.1: GSM modem (1-port) converter detected
[22633.532500] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB1
[22633.532749] option 1-1:1.2: GSM modem (1-port) converter detected
[22633.533045] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB2
[22633.533152] option 1-1:1.3: GSM modem (1-port) converter detected
[22633.533507] usb 1-1: GSM modem (1-port) converter now attached to ttyUSB3
Can we then conclude that this is probably a Linux kernel issue?