external harddrive (usb3) > kernel tainted

steigerth

New Member
Dec 1, 2022
1
0
1
I recently updated my proxmox host to the newest version 7.3-3. Before updating (7.2), the system was operating without any problems. After the update a portable external hard drive (usb3 connection, permanently connected with proxmox) is not working properly. I have created a ZFS disk on the portable hard drive and mounted the ZFS drive on my linux guest (qemu). It is used as a backup medium, so performance is not so important.

As soon as the backup process (amanda) starts and is using the disk I can find the following error in syslog:
Bash:
Dec  7 22:39:05 proxmox kernel: [32263.227584] INFO: task txg_sync:1740 blocked for more than 120 seconds.
Dec  7 22:39:05 proxmox kernel: [32263.227589]       Tainted: P           O      5.19.17-1-pve #1
Dec  7 22:39:05 proxmox kernel: [32263.227591] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec  7 22:39:05 proxmox kernel: [32263.227592] task:txg_sync        state:D stack:    0 pid: 1740 ppid:     2 flags:0x00004000
Dec  7 22:39:05 proxmox kernel: [32263.227595] Call Trace:
Dec  7 22:39:05 proxmox kernel: [32263.227596]  <TASK>
Dec  7 22:39:05 proxmox kernel: [32263.227598]  __schedule+0x32b/0x13d0
Dec  7 22:39:05 proxmox kernel: [32263.227602]  ? __mod_timer+0x26f/0x440
Dec  7 22:39:05 proxmox kernel: [32263.227606]  schedule+0x68/0x100
Dec  7 22:39:05 proxmox kernel: [32263.227607]  schedule_timeout+0x87/0x160
Dec  7 22:39:05 proxmox kernel: [32263.227609]  ? timer_migration_handler+0xa0/0xa0
Dec  7 22:39:05 proxmox kernel: [32263.227610]  io_schedule_timeout+0x51/0x80
Dec  7 22:39:05 proxmox kernel: [32263.227612]  __cv_timedwait_common+0x136/0x170 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227617]  ? destroy_sched_domains_rcu+0x30/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227620]  __cv_timedwait_io+0x19/0x20 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227623]  zio_wait+0x137/0x300 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227679]  ? dsl_dataset_sync+0x8a/0x500 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227717]  dsl_pool_sync+0xcc/0x4f0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227763]  ? spa_suspend_async_destroy+0x60/0x60 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227806]  ? add_timer+0x20/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227809]  spa_sync+0x558/0x1020 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227848]  ? spa_txg_history_init_io+0x10a/0x120 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227887]  txg_sync_thread+0x274/0x3f0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227925]  ? txg_register_callbacks+0xb0/0xb0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227959]  ? __thread_exit+0x20/0x20 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227963]  thread_generic_wrapper+0x64/0x80 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227967]  kthread+0xf0/0x120
Dec  7 22:39:05 proxmox kernel: [32263.227969]  ? kthread_complete_and_exit+0x20/0x20
Dec  7 22:39:05 proxmox kernel: [32263.227971]  ret_from_fork+0x22/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227974]  </TASK>

Dec  7 22:39:05 proxmox kernel: [32263.227584] INFO: task txg_sync:1740 blocked for more than 120 seconds.
Dec  7 22:39:05 proxmox kernel: [32263.227589]       Tainted: P           O      5.19.17-1-pve #1
Dec  7 22:39:05 proxmox kernel: [32263.227591] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec  7 22:39:05 proxmox kernel: [32263.227592] task:txg_sync        state:D stack:    0 pid: 1740 ppid:     2 flags:0x00004000
Dec  7 22:39:05 proxmox kernel: [32263.227595] Call Trace:
Dec  7 22:39:05 proxmox kernel: [32263.227596]  <TASK>
Dec  7 22:39:05 proxmox kernel: [32263.227598]  __schedule+0x32b/0x13d0
Dec  7 22:39:05 proxmox kernel: [32263.227602]  ? __mod_timer+0x26f/0x440
Dec  7 22:39:05 proxmox kernel: [32263.227606]  schedule+0x68/0x100
Dec  7 22:39:05 proxmox kernel: [32263.227607]  schedule_timeout+0x87/0x160
Dec  7 22:39:05 proxmox kernel: [32263.227609]  ? timer_migration_handler+0xa0/0xa0
Dec  7 22:39:05 proxmox kernel: [32263.227610]  io_schedule_timeout+0x51/0x80
Dec  7 22:39:05 proxmox kernel: [32263.227612]  __cv_timedwait_common+0x136/0x170 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227617]  ? destroy_sched_domains_rcu+0x30/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227620]  __cv_timedwait_io+0x19/0x20 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227623]  zio_wait+0x137/0x300 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227679]  ? dsl_dataset_sync+0x8a/0x500 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227717]  dsl_pool_sync+0xcc/0x4f0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227763]  ? spa_suspend_async_destroy+0x60/0x60 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227806]  ? add_timer+0x20/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227809]  spa_sync+0x558/0x1020 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227848]  ? spa_txg_history_init_io+0x10a/0x120 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227887]  txg_sync_thread+0x274/0x3f0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227925]  ? txg_register_callbacks+0xb0/0xb0 [zfs]
Dec  7 22:39:05 proxmox kernel: [32263.227959]  ? __thread_exit+0x20/0x20 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227963]  thread_generic_wrapper+0x64/0x80 [spl]
Dec  7 22:39:05 proxmox kernel: [32263.227967]  kthread+0xf0/0x120
Dec  7 22:39:05 proxmox kernel: [32263.227969]  ? kthread_complete_and_exit+0x20/0x20
Dec  7 22:39:05 proxmox kernel: [32263.227971]  ret_from_fork+0x22/0x30
Dec  7 22:39:05 proxmox kernel: [32263.227974]  </TASK>



Later errors of the following kind can be found repeatedly in the syslog file:
Bash:
Dec 08 04:56:30 proxmox zed[2827]: Missed 17 events
Dec 08 04:56:30 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:56:30 proxmox zed[2827]: Missed 67 events
Dec 08 04:56:30 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:56:30 proxmox zed[2827]: Missed 73 events
Dec 08 04:56:30 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:56:30 proxmox zed[2827]: Missed 15 events
Dec 08 04:56:30 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:56:30 proxmox zed[3423767]: eid=3643 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308894720 priority=3 err=0 flags=0x184880 delay=54906832ms bookmark=261:1:0:323404549
Dec 08 04:56:30 proxmox zed[3423766]: eid=3644 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308886528 priority=3 err=0 flags=0x184880 delay=54906832ms bookmark=261:1:0:323404548
Dec 08 04:56:30 proxmox zed[3423770]: eid=3645 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308878336 priority=3 err=0 flags=0x184880 delay=54906832ms bookmark=261:1:0:323404547
Dec 08 04:56:30 proxmox zed[3423774]: eid=3646 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308870144 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404546
Dec 08 04:56:30 proxmox zed[3423775]: eid=3647 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=16384 offset=274308861952 priority=3 err=0 flags=0x40080c80 delay=54906831ms
Dec 08 04:56:30 proxmox zed[3423779]: eid=3648 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308861952 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404545
Dec 08 04:56:30 proxmox zed[3423781]: eid=3649 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=16384 offset=274308861952 priority=3 err=0 flags=0x40080c80 delay=54906831ms
Dec 08 04:56:30 proxmox zed[3423786]: eid=3650 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308853760 priority=3 err=0 flags=0x184880 delay=54906831ms bookmark=261:1:0:323404544
Dec 08 04:56:30 proxmox zed[3423787]: eid=3651 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308845568 priority=3 err=0 flags=0x184880 delay=54906830ms bookmark=261:1:0:323404543
Dec 08 04:56:30 proxmox zed[3423793]: eid=3653 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=155648 offset=274308689920 priority=3 err=0 flags=0x40080c80 delay=54906830ms
Dec 08 04:56:30 proxmox zed[3423792]: eid=3652 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308837376 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404542
Dec 08 04:56:30 proxmox zed[3423797]: eid=3654 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308829184 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404541
Dec 08 04:56:30 proxmox zed[3423799]: eid=3655 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=155648 offset=274308689920 priority=3 err=0 flags=0x40080c80 delay=54906830ms
Dec 08 04:56:30 proxmox zed[3423803]: eid=3656 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308820992 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404540
Dec 08 04:56:30 proxmox zed[3423805]: eid=3657 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=155648 offset=274308689920 priority=3 err=0 flags=0x40080c80 delay=54906830ms
Dec 08 04:56:30 proxmox zed[3423808]: eid=3658 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308812800 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404539
Dec 08 04:56:30 proxmox zed[3423813]: eid=3659 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=155648 offset=274308689920 priority=3 err=0 flags=0x40080c80 delay=54906830ms
Dec 08 04:56:30 proxmox zed[3423814]: eid=3660 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308804608 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404538
Dec 08 04:56:30 proxmox zed[3423816]: eid=3661 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=155648 offset=274308689920 priority=3 err=0 flags=0x40080c80 delay=54906830ms
Dec 08 04:56:30 proxmox zed[3423818]: eid=3662 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274308796416 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323404537
Dec 08 04:57:31 proxmox zed[2827]: Missed 5 events
Dec 08 04:57:31 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:57:31 proxmox zed[2827]: Missed 65 events
Dec 08 04:57:31 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:57:31 proxmox zed[2827]: Missed 63 events
Dec 08 04:57:31 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:57:31 proxmox zed[2827]: Missed 36 events
Dec 08 04:57:31 proxmox zed[2827]: Bumping queue length to 2147483647
Dec 08 04:57:31 proxmox zed[3428274]: eid=3664 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544861184 priority=3 err=0 flags=0x184880 bookmark=261:1:0:323433372
Dec 08 04:57:31 proxmox zed[3428272]: eid=3663 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544869376 priority=3 err=0 flags=0x184880 bookmark=261:1:0:323433373
Dec 08 04:57:31 proxmox zed[3428277]: eid=3665 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544852992 priority=3 err=0 flags=0x184880 delay=54967933ms bookmark=261:1:0:323433371
Dec 08 04:57:31 proxmox zed[3428281]: eid=3666 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544844800 priority=3 err=0 flags=0x184880 delay=54967933ms bookmark=261:1:0:323433370
Dec 08 04:57:31 proxmox zed[3428282]: eid=3667 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544836608 priority=3 err=0 flags=0x184880 delay=54967933ms bookmark=261:1:0:323433369
Dec 08 04:57:31 proxmox zed[3428286]: eid=3668 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544828416 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433368
Dec 08 04:57:31 proxmox zed[3428288]: eid=3669 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428292]: eid=3670 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544820224 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433367
Dec 08 04:57:31 proxmox zed[3428295]: eid=3671 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428298]: eid=3672 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544812032 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433366
Dec 08 04:57:31 proxmox zed[3428301]: eid=3673 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428304]: eid=3674 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544803840 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433365
Dec 08 04:57:31 proxmox zed[3428308]: eid=3675 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428309]: eid=3676 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544795648 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433364
Dec 08 04:57:31 proxmox zed[3428312]: eid=3677 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428315]: eid=3678 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544787456 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433363
Dec 08 04:57:31 proxmox zed[3428320]: eid=3679 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428321]: eid=3680 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544779264 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433362
Dec 08 04:57:31 proxmox zed[3428323]: eid=3681 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=417792 offset=274544418816 priority=3 err=0 flags=0x40080c80 delay=54967933ms
Dec 08 04:57:31 proxmox zed[3428325]: eid=3682 class=deadman pool='amanda' vdev=usb-Intenso_SCSI_2021A11316722-0:0-part1 size=8192 offset=274544771072 priority=3 err=0 flags=0x384880 bookmark=261:1:0:323433361

IO delay on proxmox host is very high during the backup, approximately between 60% to 80%.

Can anyone give me hint how I can solve this problem? Could I somehow switch back to the previous promox version?
 

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!