A strange behavior with a BU40N drive

[georgesgiralt]

Hello Guys,
I've got a BU40N drive with original firmware A100 in it. IT is into an external enclosure with an ASM105X interface chip. IT is perfectly recognized in my Ubuntu 20.04 LTS laptop :

Code: Select all

Aug  3 17:35:14  kernel: [36400.872323] pktcdvd: pktcdvd0: writer unmapped
Aug  3 17:35:42  kernel: [36428.948408] usb 2-1: new SuperSpeed USB device number 3 using xhci_hcd
Aug  3 17:35:43  kernel: [36428.969291] usb 2-1: New USB device found, idVendor=174c, idProduct=55aa, bcdDevice= 1.00
Aug  3 17:35:43  kernel: [36428.969301] usb 2-1: New USB device strings: Mfr=2, Product=3, SerialNumber=1
Aug  3 17:35:43  kernel: [36428.969304] usb 2-1: Product: ASM105X
Aug  3 17:35:43  kernel: [36428.969307] usb 2-1: Manufacturer: ASMT
Aug  3 17:35:43  kernel: [36428.969309] usb 2-1: SerialNumber: 2020082000000047
Aug  3 17:35:43  kernel: [36428.970411] usb-storage 2-1:1.0: USB Mass Storage device detected
Aug  3 17:35:43  kernel: [36428.970771] usb-storage 2-1:1.0: Quirks match for vid 174c pid 55aa: 400000
Aug  3 17:35:43  kernel: [36428.970830] scsi host1: usb-storage 2-1:1.0
Aug  3 17:34:48  rtkit-daemon[1450]: message repeated 9 times: [ Supervising 17 threads of 4 processes of 2 users.]
Aug  3 17:35:43  mtp-probe: checking bus 2, device 3: "/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-1"
Aug  3 17:35:43  mtp-probe: bus: 2, device: 3 was not an MTP device
Aug  3 17:35:43  mtp-probe: checking bus 2, device 3: "/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-1"
Aug  3 17:35:43  mtp-probe: bus: 2, device: 3 was not an MTP device
Aug  3 17:35:44  kernel: [36429.995652] scsi 1:0:0:0: CD-ROM            HL-DT-ST BD-RE BU40N      A100 PQ: 0 ANSI: 0
Aug  3 17:35:44  kernel: [36429.998613] sr 1:0:0:0: Power-on or device reset occurred
Aug  3 17:35:44  kernel: [36430.004321] sr 1:0:0:0: [sr0] scsi3-mmc drive: 24x/24x writer dvd-ram cd/rw xa/form2 cdda tray
Aug  3 17:35:44  kernel: [36430.009213] sr 1:0:0:0: Attached scsi CD-ROM sr0
Aug  3 17:35:44  kernel: [36430.009284] sr 1:0:0:0: Attached scsi generic sg1 type 5
Aug  3 17:35:44  kernel: [36430.055188] pktcdvd: pktcdvd0: writer mapped to sr0

Quite all of the DVD I drop into it are read fine and are recognized by the Ubuntu OS.

Code: Select all

Aug  3 17:42:16 kernel: [36822.602777] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:16 kernel: [36822.602785] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current]
Aug  3 17:42:16 kernel: [36822.602789] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:16 kernel: [36822.602792] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 00 02 00 00 00 02 00
Aug  3 17:42:16 kernel: [36822.602795] blk_update_request: I/O error, dev sr0, sector 2048 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
Aug  3 17:42:18 kernel: [36824.709153] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=2s
Aug  3 17:42:18 kernel: [36824.709160] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current]
Aug  3 17:42:18 kernel: [36824.709164] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:18 kernel: [36824.709168] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 00 02 00 00 00 02 00
Aug  3 17:42:18 kernel: [36824.709170] blk_update_request: I/O error, dev sr0, sector 2048 op 0x0:(READ) flags 0x0 phys_seg 2 prio class 0
Aug  3 17:42:18 kernel: [36824.709181] Buffer I/O error on dev sr0, logical block 512, async page read
Aug  3 17:42:18 kernel: [36824.709186] Buffer I/O error on dev sr0, logical block 513, async page read
Aug  3 17:42:21 kernel: [36827.793698] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:21 kernel: [36827.793707] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current] 
Aug  3 17:42:21 kernel: [36827.793711] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:21 kernel: [36827.793715] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 3e d6 00 00 00 80 00 
Aug  3 17:42:21 kernel: [36827.793717] blk_update_request: I/O error, dev sr0, sector 16472064 op 0x0:(READ) flags 0x80700 phys_seg 64 prio class 0
Aug  3 17:42:21 kernel: [36827.857926] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:21 kernel: [36827.857933] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current] 
Aug  3 17:42:21 kernel: [36827.857937] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:21 kernel: [36827.857940] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 3e d6 00 00 00 01 00 
Aug  3 17:42:21 kernel: [36827.857942] blk_update_request: I/O error, dev sr0, sector 16472064 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Aug  3 17:42:21 kernel: [36827.857952] Buffer I/O error on dev sr0, logical block 4118016, async page read
Aug  3 17:42:22 kernel: [36828.077319] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:22 kernel: [36828.077327] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current] 
Aug  3 17:42:22 kernel: [36828.077331] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:22 kernel: [36828.077334] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 00 04 00 00 00 02 00 
Aug  3 17:42:22 kernel: [36828.077336] blk_update_request: I/O error, dev sr0, sector 4096 op 0x0:(READ) flags 0x80700 phys_seg 1 prio class 0
Aug  3 17:42:22 kernel: [36828.142040] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:22 kernel: [36828.142047] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current] 
Aug  3 17:42:22 kernel: [36828.142051] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:22 kernel: [36828.142054] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 00 04 00 00 00 01 00 
Aug  3 17:42:22 kernel: [36828.142056] blk_update_request: I/O error, dev sr0, sector 4096 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Aug  3 17:42:22 kernel: [36828.142065] Buffer I/O error on dev sr0, logical block 1024, async page read
Aug  3 17:42:22 kernel: [36828.207585] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
Aug  3 17:42:22 kernel: [36828.207592] sr 1:0:0:0: [sr0] tag#0 Sense Key : Illegal Request [current] 
Aug  3 17:42:22 kernel: [36828.207596] sr 1:0:0:0: [sr0] tag#0 Add. Sense: Read of scrambled sector without authentication
Aug  3 17:42:22 kernel: [36828.207599] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 00 04 01 00 00 01 00 
Aug  3 17:42:22 kernel: [36828.207601] blk_update_request: I/O error, dev sr0, sector 4100 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Aug  3 17:42:22 kernel: [36828.207610] Buffer I/O error on dev sr0, logical block 1025, async page read
Aug  3 17:42:22 kernel: [36828.416860] UDF-fs: INFO Mounting volume 'THE_PEACEMAKER', timestamp 1998/11/19 00:05 (1000)
Aug  3 17:42:22 dbus-daemon[1449]: [session uid=124 pid=1449] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.3' (uid=124 pid=1440 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Aug  3 17:42:22 systemd[1424]: Starting Tracker metadata database store and lookup manager...
Aug  3 17:42:22 dbus-daemon[2000]: [session uid=1000 pid=2000] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.2' (uid=1000 pid=1996 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Aug  3 17:42:22 systemd[1]: Created slice system-clean\x2dmount\x2dpoint.slice.
Aug  3 17:42:22 systemd[1]: Finished Clean the /media/georges/THE_PEACEMAKER mount point.
Aug  3 17:42:22 systemd[1988]: Starting Tracker metadata database store and lookup manager...
Aug  3 17:42:22 udisksd[1082]: Mounted /dev/sr0 at /media/georges/THE_PEACEMAKER on behalf of uid 1000 
Aug  3 17:42:22 dbus-daemon[1449]: [session uid=124 pid=1449] Successfully activated service 'org.freedesktop.Tracker1'
Aug  3 17:42:22 systemd[1424]: Started Tracker metadata database store and lookup manager. 
Aug  3 17:42:22 dbus-daemon[2000]: [session uid=1000 pid=2000] Successfully activated service 'org.freedesktop.Tracker1'
Aug  3 17:42:22 systemd[1988]: Started Tracker metadata database store and lookup manager.
Aug  3 17:42:52 tracker-store[62622]: OK
Aug  3 17:42:52 systemd[1988]: tracker-store.service: Succeeded.
Aug  3 17:42:52 tracker-store[62620]: OK
Aug  3 17:42:52 systemd[1424]: tracker-store.service: Succeeded.

So I can watch "The peacemaker" with Ms Kidman and Mr Clooney. using VLC. Perfect.
If I remove this DVD and install another one (here "Apollo 13 Collector Edition" movie with Mr Hanks), I get a very different behaviour :
(Both DVD are Region 1 and my drive is seen as "region less" by MAkeMKV)

Code: Select all

ug  3 17:49:30 espineux kernel: [37256.399325] VFS: busy inodes on changed media sr0
Aug  3 17:49:30 espineux systemd[1]: Unmounting /media/georges/THE_PEACEMAKER...
Aug  3 17:49:30 espineux udisksd[1082]: Cleaning up mount point /media/georges/THE_PEACEMAKER (device 11:0 is not mounted)
Aug  3 17:49:30 espineux systemd[1424]: media-georges-THE_PEACEMAKER.mount: Succeeded.
Aug  3 17:49:30 espineux systemd[1]: media-georges-THE_PEACEMAKER.mount: Succeeded.
Aug  3 17:49:30 espineux systemd[1988]: media-georges-THE_PEACEMAKER.mount: Succeeded.
Aug  3 17:49:30 espineux systemd[1]: Unmounted /media/georges/THE_PEACEMAKER.
Aug  3 17:49:30 espineux dbus-daemon[2000]: [session uid=1000 pid=2000] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.2' (uid=1000 pid=1996 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Aug  3 17:49:30 espineux systemd[1988]: Starting Tracker metadata database store and lookup manager...
Aug  3 17:49:30 espineux dbus-daemon[1449]: [session uid=124 pid=1449] Activating via systemd: service name='org.freedesktop.Tracker1' unit='tracker-store.service' requested by ':1.3' (uid=124 pid=1440 comm="/usr/libexec/tracker-miner-fs " label="unconfined")
Aug  3 17:49:30 espineux systemd[1]: Stopping Clean the /media/georges/THE_PEACEMAKER mount point...
Aug  3 17:49:30 espineux systemd[1424]: Starting Tracker metadata database store and lookup manager...
Aug  3 17:49:30 espineux systemd[1]: clean-mount-point@media-georges-THE_PEACEMAKER.service: Succeeded.
Aug  3 17:49:30 espineux systemd[1]: Stopped Clean the /media/georges/THE_PEACEMAKER mount point.
Aug  3 17:49:30 espineux dbus-daemon[2000]: [session uid=1000 pid=2000] Successfully activated service 'org.freedesktop.Tracker1'
Aug  3 17:49:30 espineux systemd[1988]: Started Tracker metadata database store and lookup manager.
Aug  3 17:49:30 espineux dbus-daemon[1449]: [session uid=124 pid=1449] Successfully activated service 'org.freedesktop.Tracker1'
Aug  3 17:49:30 espineux systemd[1424]: Started Tracker metadata database store and lookup manager.
Aug  3 17:49:32 espineux wpa_supplicant[1084]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-67 noise=9999 txrate=780000
Aug  3 17:49:41 espineux wpa_supplicant[1084]: wlp0s20f3: CTRL-EVENT-SIGNAL-CHANGE above=1 signal=-57 noise=9999 txrate=780000
Aug  3 17:49:49 espineux rtkit-daemon[1450]: Supervising 17 threads of 4 processes of 2 users.
Aug  3 17:49:51 espineux rtkit-daemon[1450]: message repeated 3 times: [ Supervising 17 threads of 4 processes of 2 users.]
Aug  3 17:50:00 espineux tracker-store[63223]: OK
Aug  3 17:50:00 espineux systemd[1988]: tracker-store.service: Succeeded.
Aug  3 17:50:00 espineux tracker-store[63226]: OK
Aug  3 17:50:00 espineux systemd[1424]: tracker-store.service: Succeeded.
Aug  3 17:51:02  kernel: [37348.957292] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
Aug  3 17:51:02  kernel: [37348.978587] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
Aug  3 17:51:02  kernel: [37348.978595] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 3f 40 80 00 00 80 00
Aug  3 17:51:02  kernel: [37348.978597] blk_update_request: I/O error, dev sr0, sector 16581120 op 0x0:(READ) flags 0x80700 phys_seg 64 prio class 0 
Aug  3 17:51:25  systemd-udevd[500]: sr0: Worker [63345] processing SEQNUM=6616 is taking a long time
Aug  3 17:51:33  kernel: [37379.670590] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
Aug  3 17:53:25  systemd-udevd[500]: sr0: Worker [63345] processing SEQNUM=6616 killed
Aug  3 17:53:25  systemd-udevd[500]: Worker [63345] terminated by signal 9 (KILL)
Aug  3 17:53:25  systemd-udevd[500]: sr0: Worker [63345] failed

And the drive is stuck. And the Ubuntu OS also. I can't use the drive anymore.
The dmesg ring buffer has a little more information :

Code: Select all

37348.957292] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
[37348.978587] sr 1:0:0:0: [sr0] tag#0 FAILED Result: hostbyte=DID_TIME_OUT driverbyte=DRIVER_OK cmd_age=31s
[37348.978595] sr 1:0:0:0: [sr0] tag#0 CDB: Read(10) 28 00 00 3f 40 80 00 00 80 00
[37348.978597] blk_update_request: I/O error, dev sr0, sector 16581120 op 0x0:(READ) flags 0x80700 phys_seg 64 prio class 0
[37379.670590] usb 2-1: reset SuperSpeed USB device number 3 using xhci_hcd
[37580.241784] INFO: task scsi_eh_1:61992 blocked for more than 120 seconds.
[37580.241794]       Tainted: P           O      5.15.0-43-generic #46~20.04.1-Ubuntu
[37580.241797] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[37580.241799] task:scsi_eh_1       state:D stack:    0 pid:61992 ppid:     2 flags:0x00004000
[37580.241806] Call Trace:
[37580.241808]  <TASK>
[37580.241812]  __schedule+0x2cd/0x890
[37580.241819]  ? newidle_balance+0x12a/0x470
[37580.241825]  schedule+0x4e/0xb0
[37580.241829]  schedule_preempt_disabled+0xe/0x10
[37580.241832]  __mutex_lock.isra.0+0x208/0x470
[37580.241837]  ? bt_tags_iter+0x92/0xd0
[37580.241842]  __mutex_lock_slowpath+0x13/0x20
[37580.241846]  mutex_lock+0x32/0x40
[37580.241852]  device_reset+0x22/0x50 [usb_storage]
[37580.241858]  scsi_eh_ready_devs+0x57d/0xa70
[37580.241863]  ? __pm_runtime_resume+0x60/0x80
[37580.241867]  scsi_error_handler+0x437/0x520
[37580.241872]  ? scsi_eh_get_sense+0x250/0x250
[37580.241876]  kthread+0x127/0x150
[37580.241880]  ? set_kthread_struct+0x40/0x40
[37580.241883]  ret_from_fork+0x1f/0x30
[37580.241890]  </TASK>
[37580.241891] INFO: task usb-storage:61994 blocked for more than 120 seconds.
[37580.241895]       Tainted: P           O      5.15.0-43-generic #46~20.04.1-Ubuntu
[37580.241897] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[37580.241899] task:usb-storage     state:D stack:    0 pid:61994 ppid:     2 flags:0x00004000
[37580.241903] Call Trace:
[37580.241904]  <TASK>
[37580.241906]  __schedule+0x2cd/0x890
[37580.241909]  ? usleep_range_state+0x90/0x90
[37580.241914]  schedule+0x4e/0xb0
[37580.241917]  schedule_timeout+0x202/0x2c0
[37580.241922]  ? usleep_range_state+0x90/0x90
[37580.241925]  __wait_for_common+0xb0/0x160
[37580.241929]  wait_for_completion+0x24/0x30
[37580.241933]  usb_sg_wait+0xea/0x170
[37580.241938]  usb_stor_bulk_transfer_sglist+0x97/0xe0 [usb_storage]
[37580.241945]  usb_stor_bulk_srb+0x3d/0x70 [usb_storage]
[37580.241951]  usb_stor_Bulk_transport+0x177/0x410 [usb_storage]
[37580.241956]  ? schedule_timeout+0x202/0x2c0
[37580.241960]  usb_stor_invoke_transport+0x3b/0x520 [usb_storage]
[37580.241967]  ? usleep_range_state+0x90/0x90
[37580.241970]  ? __wait_for_common+0xf7/0x160
[37580.241974]  usb_stor_transparent_scsi_command+0xe/0x10 [usb_storage]
[37580.241980]  usb_stor_control_thread+0x198/0x290 [usb_storage]
[37580.241986]  ? storage_probe+0x2b0/0x2b0 [usb_storage]
[37580.241992]  kthread+0x127/0x150
[37580.241995]  ? set_kthread_struct+0x40/0x40
[37580.241998]  ret_from_fork+0x1f/0x30
[37580.242004]  </TASK>
[37701.077594] INFO: task udisksd:1082 blocked for more than 120 seconds.
[37701.077605]       Tainted: P           O      5.15.0-43-generic #46~20.04.1-Ubuntu
[37701.077609] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[37701.077610] task:udisksd         state:D stack:    0 pid: 1082 ppid:     1 flags:0x00000000
[37701.077618] Call Trace:
[37701.077621]  <TASK>
[37701.077625]  __schedule+0x2cd/0x890
[37701.077634]  ? enqueue_entity+0x10f/0x6f0
[37701.077640]  ? usleep_range_state+0x90/0x90
[37701.077645]  schedule+0x4e/0xb0
[37701.077649]  schedule_timeout+0x202/0x2c0
[37701.077654]  ? ttwu_do_wakeup+0x1c/0x170
[37701.077659]  ? ttwu_do_activate+0x9f/0x570
[37701.077663]  ? usleep_range_state+0x90/0x90
[37701.077668]  __wait_for_common+0xb0/0x160
[37701.077672]  wait_for_completion+0x24/0x30
[37701.077677]  __flush_work+0x153/0x240
[37701.077682]  ? worker_detach_from_pool+0xc0/0xc0
[37701.077687]  __cancel_work_timer+0x12c/0x1b0
[37701.077692]  ? find_inode_fast.isra.0+0x59/0xc0
[37701.077698]  cancel_delayed_work_sync+0x13/0x20
[37701.077703]  disk_block_events+0x78/0x80
[37701.077709]  blkdev_get_by_dev+0x111/0x2d0
[37701.077714]  ? blkdev_close+0x30/0x30
[37701.077719]  blkdev_open+0x50/0x90
[37701.077723]  do_dentry_open+0x157/0x380
[37701.077728]  vfs_open+0x2d/0x30
[37701.077734]  path_openat+0xb48/0x1150
[37701.077740]  do_filp_open+0xb2/0x120
[37701.077745]  ? __check_object_size+0x13f/0x150
[37701.077750]  do_sys_openat2+0x245/0x320
[37701.077755]  do_sys_open+0x46/0x80
[37701.077760]  __x64_sys_openat+0x20/0x30
[37701.077765]  do_syscall_64+0x59/0xc0
[37701.077770]  ? syscall_exit_to_user_mode+0x27/0x50
[37701.077775]  ? __x64_sys_newfstat+0x16/0x20
[37701.077780]  ? do_syscall_64+0x69/0xc0
[37701.077783]  ? irqentry_exit+0x19/0x30
[37701.077788]  ? exc_page_fault+0x89/0x160
[37701.077793]  ? asm_exc_page_fault+0x8/0x30
[37701.077796]  entry_SYSCALL_64_after_hwframe+0x44/0xae
[37701.077802] RIP: 0033:0x7f78d2618b34
[37701.077807] RSP: 002b:00007ffc3f099ee0 EFLAGS: 00000293 ORIG_RAX: 0000000000000101
[37701.077812] RAX: ffffffffffffffda RBX: 00007ffc3f09a00c RCX: 00007f78d2618b34
[37701.077815] RDX: 0000000000000000 RSI: 000055fdea8a8a70 RDI: 00000000ffffff9c
[37701.077817] RBP: 000055fdea8a8a70 R08: 0000000000000000 R09: 000000000000000b
[37701.077820] R10: 0000000000000000 R11: 0000000000000293 R12: 0000000000000000
[37701.077822] R13: 0000000000000000 R14: 000055fdea8a8a70 R15: 000055fdea919ce0
[37701.077826]  </TASK>
[37701.078094] INFO: task scsi_eh_1:61992 blocked for more than 241 seconds.
[37701.078098]       Tainted: P           O      5.15.0-43-generic #46~20.04.1-Ubuntu
[37701.078101] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[37701.078102] task:scsi_eh_1       state:D stack:    0 pid:61992 ppid:     2 flags:0x00004000
[37701.078107] Call Trace:
[37701.078109]  <TASK>
[37701.078111]  __schedule+0x2cd/0x890
[37701.078115]  ? newidle_balance+0x12a/0x470
[37701.078120]  schedule+0x4e/0xb0
[37701.078124]  schedule_preempt_disabled+0xe/0x10
[37701.078129]  __mutex_lock.isra.0+0x208/0x470
[37701.078133]  ? bt_tags_iter+0x92/0xd0
[37701.078139]  __mutex_lock_slowpath+0x13/0x20
[37701.078143]  mutex_lock+0x32/0x40
[37701.078150]  device_reset+0x22/0x50 [usb_storage]
[37701.078157]  scsi_eh_ready_devs+0x57d/0xa70
[37701.078164]  ? __pm_runtime_resume+0x60/0x80
[37701.078168]  scsi_error_handler+0x437/0x520
[37701.078173]  ? scsi_eh_get_sense+0x250/0x250
[37701.078178]  kthread+0x127/0x150
[37701.078182]  ? set_kthread_struct+0x40/0x40
[37701.078187]  ret_from_fork+0x1f/0x30
[37701.078194]  </TASK>
[37701.078196] INFO: task usb-storage:61994 blocked for more than 241 seconds.
[37701.078199]       Tainted: P           O      5.15.0-43-generic #46~20.04.1-Ubuntu
[37701.078202] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[37701.078203] task:usb-storage     state:D stack:    0 pid:61994 ppid:     2 flags:0x00004000
[37701.078207] Call Trace:
[37701.078208]  <TASK>
[37701.078210]  __schedule+0x2cd/0x890
[37701.078214]  ? usleep_range_state+0x90/0x90
[37701.078219]  schedule+0x4e/0xb0
[37701.078223]  schedule_timeout+0x202/0x2c0
[37701.078228]  ? usleep_range_state+0x90/0x90
[37701.078233]  __wait_for_common+0xb0/0x160
[37701.078237]  wait_for_completion+0x24/0x30
[37701.078241]  usb_sg_wait+0xea/0x170
[37701.078248]  usb_stor_bulk_transfer_sglist+0x97/0xe0 [usb_storage]
[37701.078255]  usb_stor_bulk_srb+0x3d/0x70 [usb_storage]
[37701.078262]  usb_stor_Bulk_transport+0x177/0x410 [usb_storage]
[37701.078268]  ? schedule_timeout+0x202/0x2c0
[37701.078273]  usb_stor_invoke_transport+0x3b/0x520 [usb_storage]
[37701.078280]  ? usleep_range_state+0x90/0x90
[37701.078285]  ? __wait_for_common+0xf7/0x160
[37701.078290]  usb_stor_transparent_scsi_command+0xe/0x10 [usb_storage]
[37701.078296]  usb_stor_control_thread+0x198/0x290 [usb_storage]
[37701.078303]  ? storage_probe+0x2b0/0x2b0 [usb_storage]
[37701.078310]  kthread+0x127/0x150
[37701.078314]  ? set_kthread_struct+0x40/0x40
[37701.078317]  ret_from_fork+0x1f/0x30
[37701.078323]  </TASK>

It is not related to the USB interface box because I tried with a friend HL-DT plain DVD writer into this box and "Apollo 13 Collector Edition" ran fine in it.
It seems not to be the BU40N hardware at fault because it can read/write CD, DVD single and dual layers and BD dics.
It is not the software because on this same laptop, the Apollo 13 DVD reads fine in another drive...
So I'm very very annoyed by this and would like to know what to do, or look for ?
Could it be a bug in the firmware ?
Please help me.
Many thanks in advance for your help.

[Billycar11]

Looks like there is a device reset in there may need more power

[georgesgiralt]

Thank you for your answer.
I do not think there is a power problem. For two reasons :
1) the drive is plugged in USB-C port on the laptop ---> do not work.
2) the drive is plugged using USB-C cable to a Thunderbolt hub powered with a 90W box ---> do not work.
This same setup can read and write anything I throw at it except some DVD which refuse to read. So I may be wrong but power is sufficient. I'm also, like you puzzled by the device resetting. But I wonder what is the cause ?

[georgesgiralt]

Hello,
I remembered that I had a Windows sitting on a part of the NVME card in the laptop.
So I fired that Windows 11 up and, bingo ! The Apollo 13 DVD opened up and play fine in MakeMkv... (and in VLC for that matter).
So I rebooted in Ubuntu just to see that the DVD is showing .
It seems that once the drive got the keys, if not powered off, it keeps them and one can access the disc.
Weird but ?
So it is either firmware related or Ubuntu related ? I don't know.
I've checked that the drive has original firmware.

Code: Select all

Informations lecteur
Nom du lecteur SE : /dev/sr0
Fabricant : HL-DT-ST
Produit : BD-RE BU40N
Révision : A100
Numéro de série : KZDH1DC1211
Date micrologiciel : 2117-01-02 11:59
Marqueurs d'encryptage bus : 1F
Version AACS la plus haute : 68

LibreDrive Information
Status: Enabled
Drive platform: MT1959
Firmware type: Original (unpatched)
Firmware version: 0.A100D
DVD all regions: Yes
BD raw data read: Yes
BD raw metadata read: Yes
Unrestricted read speed: Yes

Questions :
1) if I save the A100 firmware from the drive, will I be able to burn it back again ?
2) do you think I'll benefit flashing the DE_LG_BU40N_1.00.bin which is in the archive ?
Thanks in advance for your help and insights !

[MartyMcNuts]

Hello,
I remembered that I had a Windows sitting on a part of the NVME card in the laptop.
So I fired that Windows 11 up and, bingo ! The Apollo 13 DVD opened up and play fine in MakeMkv... (and in VLC for that matter).
So I rebooted in Ubuntu just to see that the DVD is showing .
It seems that once the drive got the keys, if not powered off, it keeps them and one can access the disc.
Weird but ?
So it is either firmware related or Ubuntu related ? I don't know.
I've checked that the drive has original firmware.

Code: Select all

Informations lecteur
Nom du lecteur SE : /dev/sr0
Fabricant : HL-DT-ST
Produit : BD-RE BU40N
Révision : A100
Numéro de série : KZDH1DC1211
Date micrologiciel : 2117-01-02 11:59
Marqueurs d'encryptage bus : 1F
Version AACS la plus haute : 68

LibreDrive Information
Status: Enabled
Drive platform: MT1959
Firmware type: Original (unpatched)
Firmware version: 0.A100D
DVD all regions: Yes
BD raw data read: Yes
BD raw metadata read: Yes
Unrestricted read speed: Yes

Questions :
1) if I save the A100 firmware from the drive, will I be able to burn it back again ?
2) do you think I'll benefit flashing the DE_LG_BU40N_1.00.bin which is in the archive ?
Thanks in advance for your help and insights !

Honestly, if it works fine in windows then the drive is not your issue. I'd leave it as is.

[georgesgiralt]

Thank you for your answer, but I would like to narrow the issue as far as I can and report it back to the Ubuntu people. So I would like if I can to change the firmware of the drive to check if it is firmware+Ubuntu or firmware alone. *
What puzzle me is that when I tried a "plain" DVD drive in the very same hardware/software, it ran fine. (it was a pita to open the enclosure, though). And the DVD reader was from the "same" maker so may share some parts of the firmware.
So my question remains : If I save the original firmware from the drive, will it be possible to put it back ? And which firmware to use ? DE_LG_BU40N_1.00.bin or HL-DT-ST-BD-RE_BU40N-1.03-NM00000-211810241934.bin ? I'm somewhat confused bat what I read on this forum .....
Have a nice and bright day !

[MartyMcNuts]

Thank you for your answer, but I would like to narrow the issue as far as I can and report it back to the Ubuntu people. So I would like if I can to change the firmware of the drive to check if it is firmware+Ubuntu or firmware alone. *
What puzzle me is that when I tried a "plain" DVD drive in the very same hardware/software, it ran fine. (it was a pita to open the enclosure, though). And the DVD reader was from the "same" maker so may share some parts of the firmware.
So my question remains : If I save the original firmware from the drive, will it be possible to put it back ? And which firmware to use ? DE_LG_BU40N_1.00.bin or HL-DT-ST-BD-RE_BU40N-1.03-NM00000-211810241934.bin ? I'm somewhat confused bat what I read on this forum .....
Have a nice and bright day !

You could try using SDFtool Flasher on windows to read (extract) your firmware file. It will do a full firmware copy if possible (2mb bin file) otherwise it will just extract the important parts (70kb tar file).

Another option to extract the complete firmware file is the old dosflash method. Your PC needs to be capable of changing to IDE mode in BIOS for it to work.

Since A100 is an older (and uncommon) firmware version, I would not flash the drive unless I was able to extract the full firmware file first. If you are avle to extract the full firmware file and want to proceed with flashing another firmware, I would suggest using DE BU40N 1.00.

[georgesgiralt]

Hello MartyMcNuts,
I've used this command : "sdftool -d /dev/sr0 dump full" to dump the firmware from the drive and I've got a 2MB file. And I've got "dump_full_HL-DT-ST_BD-RE_BU40N_A100_211701021159_KZDH1DC1211.bin" file...
For what I was able to look into this file, it looks like firmware to me.
I'll try to run : "makemkvcon f -d /dev/sr0 -f SoftAndbinaries/sdf.bin rawflash main -i SoftAndbinaries/DE_LG_BU40N_1.00.bin" as you suggest and report back....
I've got the DE_LG_BU40N_1.00.bin from a zip file which did not originate from this web site. I got the link from a post in this forum, though.... But I can't remember which one having read tons of posts in this forums...
Thank for your help !
Edit : The firmware I got was from : https://download2276.mediafire.com/1a8n ... e-pack.zip".

[georgesgiralt]

Hello,
I was dragging my feet for the firmware update. As a long time Unix system Engineer, I know it takes two to make a bug or a fault. So I though that if the drive is doing fine into Windows 11 OS, it was not 100% it's fault.
So I dig deeper in your forum and in the Linux part of it. And I found this thread : viewtopic.php?f=3&t=25357
Basically this mod tell the system not to try to open the disc in the drive and not mount it.
So it won't fail at opening it....
And you know what ? Apollo 13 DVD is read fine both in VLC and in MakeMKV.
But there is a collateral.
As you do not read the DVD at the system level, the file manager does not sees it because it is not mounted and you have to revert to the old fashioned way to do it. Use root powers to mount it with your fingers and the keyboard....
I'll wait a couple of days to accustom myself to the idea of flashing a "new" firmware in the drive and try the drive side of things, just to see if it changes something.
But the firmware which was int the drive when I got it is nice because it is "region free" for DVD (and I thought the drive locked itself into one region code after reading a certain number of DVDs) so loosing it will definitely be a drawback.
Thanks a lot for your help and advice !


P.S. : I got this drive second hand from China. It came into a second hand Lenovo laptop I bought for the cases I needed to repair mine. And the case was pretty, but the innards where toast except for the Blu Ray player.... So that may explain the strange firmware maybe someone modded it or changed it at some point.