LXC Container Backup stuck

[Kharne]

Hi,

we´re running two 4.4.18 nodes in a cluster. On one we have a LXC container with Ubuntu 14.04 that has 500GB disc space (currently about 270 GB actually used) and mounts a lot of other stuff. The backup for this machine started to fail periodically as it grew in size until now where the backup fails every single day.

Backups are set up over the GUI. and written onto discs connected with USB 3.0 that are mounted/umounted by cronjob every day. The backups of the machine are now about 140GB (if they work) and take about 1,5 hours. The VM is set up on a lvm storage, that has 1TiB Space, using the standard Ubuntu 14.04 Template downloadable directly in the GUI.

The backup job starts normally, opens a writer stream, but then it seems to be stuck. If it becomes stuck, the whole Server becomes unresponsive and has to be shutdown hard, because it doesn´t shutdown properly. In the syslog I found no obvious error. However, I have no idea what to look for.I have searched a lot and found multiple Threads about similar problems, but no real solution for them.

Spoiler: Syslog

Oct 12 23:00:01 proxmox-1 CRON[12650]: (root) CMD (vzdump 109 --compress lzo --mailto me --mode suspend --mailnotification always --quiet 1 --storage Proxmox-1_Backup --node proxmox-1)
Oct 12 23:00:02 proxmox-1 vzdump[12651]: <root@pam> starting task UPIDroxmox-1:000031BB:00D25609:59DFD7D2:vzdump::root@pam:
Oct 12 23:00:02 proxmox-1 vzdump[12731]: INFO: starting new backup job: vzdump 109 --compress lzo --node proxmox-1 --mailto me --quiet 1 --mailnotification always --mode suspend --storage Proxmox-1_Backup
Oct 12 23:00:02 proxmox-1 vzdump[12731]: INFO: Starting Backup of VM 109 (lxc)
Oct 12 23:01:07 proxmox-1 kernel: [137910.963311] sd 6:0:0:0: [sdb] tag#10 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.963316] sd 6:0:0:0: [sdb] tag#10 CDB: Write(16) 8a 00 00 00 00 01 5d 96 42 b8 00 00 00 f0 00 00
Oct 12 23:01:07 proxmox-1 kernel: [137910.963540] sd 6:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.963542] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 01 5d 96 41 c8 00 00 00 f0 00 00
Oct 12 23:01:07 proxmox-1 kernel: [137910.963641] sd 6:0:0:0: [sdb] tag#8 uas_eh_abort_handler 0 uas-tag 9 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.963643] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 01 5d 96 40 d8 00 00 00 f0 00 00
Oct 12 23:01:07 proxmox-1 kernel: [137910.963692] sd 6:0:0:0: [sdb] tag#7 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.963893] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.963962] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 01 5d 96 3e 08 00 00 00 f0 00 00
Oct 12 23:01:07 proxmox-1 kernel: [137910.964390] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.964515] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 01 5d 96 3b a8 00 00 00 80 00 00
Oct 12 23:01:07 proxmox-1 kernel: [137910.964897] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:01:07 proxmox-1 kernel: [137910.964940] sd 6:0:0:0: [sdb] tag#11 CDB: Write(16) 8a 00 00 00 00 01 5d 96 38 d8 00 00 00 f0 00 00
Oct 12 23:01:08 proxmox-1 pvestatd[1331]: status update time (22.039 seconds)
Oct 12 23:01:56 proxmox-1 pvestatd[1331]: status update time (27.861 seconds)
Oct 12 23:02:46 proxmox-1 kernel: [138010.084152] usb 10-2: reset SuperSpeed USB device number 2 using xhci_hcd
Oct 12 23:02:47 proxmox-1 pvestatd[1331]: status update time (31.246 seconds)
Oct 12 23:03:34 proxmox-1 pvestatd[1331]: status update time (27.257 seconds)
Oct 12 23:08:29 proxmox-1 pvestatd[1331]: status update time (24.497 seconds)
Oct 12 23:11:55 proxmox-1 kernel: [138558.962205] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 ea 36 52 88 00 00 00 f0 00 00
Oct 12 23:11:55 proxmox-1 kernel: [138558.962418] sd 6:0:0:0: [sdb] tag#7 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
Oct 12 23:11:55 proxmox-1 kernel: [138558.962480] sd 6:0:0:0: [sdb] tag#6 CDB: Write(16) 8a 00 00 00 00 00 ea 36 50 28 00 00 00 f0 00 00
Oct 12 23:11:55 proxmox-1 kernel: [138558.962724] sd 6:0:0:0: [sdb] tag#4 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
Oct 12 23:11:55 proxmox-1 kernel: [138558.962923] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 ea 36 4d b8 00 00 00 f0 00 00
Oct 12 23:11:55 proxmox-1 kernel: [138558.962975] usb 10-2: stat urb: no pending cmd for uas-tag 4
Oct 12 23:12:26 proxmox-1 pvestatd[1331]: status update time (57.123 seconds)
Oct 12 23:15:10 proxmox-1 pvestatd[1331]: status update time (24.121 seconds)
Oct 12 23:15:43 proxmox-1 pvestatd[1331]: status update time (23.361 seconds)
Oct 12 23:16:15 proxmox-1 pvestatd[1331]: status update time (22.069 seconds)
Oct 12 23:16:45 proxmox-1 pvestatd[1331]: status update time (10.182 seconds)
Oct 12 23:17:01 proxmox-1 CRON[30013]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Oct 12 23:17:20 proxmox-1 pvestatd[1331]: status update time (5.493 seconds)
Oct 12 23:19:13 proxmox-1 kernel: [138996.912728] sd 6:0:0:0: [sdb] tag#7 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:19:13 proxmox-1 kernel: [138996.913040] sd 6:0:0:0: [sdb] tag#5 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
Oct 12 23:19:13 proxmox-1 kernel: [138996.913290] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
Oct 12 23:19:13 proxmox-1 kernel: [138996.913422] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 11 inflight:
Oct 12 23:19:13 proxmox-1 kernel: [138996.913435] sd 6:0:0:0: [sdb] tag#11 uas_eh_abort_handler 0 uas-tag 2 inflight:
Oct 12 23:19:13 proxmox-1 kernel: [138997.046582] scsi host6: uas_eh_bus_reset_handler success
Oct 12 23:19:14 proxmox-1 pvestatd[1331]: status update time (29.007 seconds)
Oct 12 23:20:15 proxmox-1 pvestatd[1331]: status update time (10.862 seconds)
Oct 12 23:20:48 proxmox-1 pvestatd[1331]: status update time (12.740 seconds)
Oct 12 23:22:30 proxmox-1 kernel: [139194.081215] usb 10-2: reset SuperSpeed USB device number 2 using xhci_hcd
Oct 12 23:22:31 proxmox-1 pvestatd[1331]: status update time (23.034 seconds)
Oct 12 23:23:02 proxmox-1 pvestatd[1331]: status update time (30.989 seconds)
Oct 12 23:23:43 proxmox-1 kernel: [139267.055815] sd 6:0:0:0: tag#12 uas_eh_abort_handler 0 uas-tag 13 inflight: CMD
Oct 12 23:23:43 proxmox-1 kernel: [139267.055821] sd 6:0:0:0: tag#12 CDB: Test Unit Ready 00 00 00 00 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.055825] sd 6:0:0:0: [sdb] tag#4 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.055827] sd 6:0:0:0: [sdb] tag#4 CDB: Write(16) 8a 00 00 00 00 00 03 16 f9 38 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.055952] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.055957] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 03 16 f8 48 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.056075] sd 6:0:0:0: [sdb] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.056078] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 03 16 f7 c8 00 00 00 80 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.056180] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.056183] sd 6:0:0:0: [sdb] tag#1 CDB: Write(16) 8a 00 00 00 00 00 03 16 f6 d8 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.056322] usb 10-2: stat urb: no pending cmd for uas-tag 13
Oct 12 23:23:43 proxmox-1 kernel: [139267.056704] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.056706] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 03 16 f5 e8 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.056824] sd 6:0:0:0: [sdb] tag#11 uas_eh_abort_handler 0 uas-tag 12 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.056827] sd 6:0:0:0: [sdb] tag#11 CDB: Write(16) 8a 00 00 00 00 00 03 16 f4 f8 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.056937] sd 6:0:0:0: [sdb] tag#10 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.056940] sd 6:0:0:0: [sdb] tag#10 CDB: Write(16) 8a 00 00 00 00 00 03 16 f4 08 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057073] sd 6:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.057076] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 03 16 f3 18 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057121] sd 6:0:0:0: [sdb] tag#8 uas_eh_abort_handler 0 uas-tag 9 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.057123] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 00 03 16 f2 28 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057318] sd 6:0:0:0: [sdb] tag#7 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
Oct 12 23:23:43 proxmox-1 kernel: [139267.057320] sd 6:0:0:0: [sdb] tag#7 CDB: Write(16) 8a 00 00 00 00 00 03 16 f1 38 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057422] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 7 inflight:
Oct 12 23:23:43 proxmox-1 kernel: [139267.057425] sd 6:0:0:0: [sdb] tag#6 CDB: Write(16) 8a 00 00 00 00 00 03 16 f0 48 00 00 00 f0 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057427] sd 6:0:0:0: [sdb] tag#5 uas_eh_abort_handler 0 uas-tag 6 inflight:
Oct 12 23:23:43 proxmox-1 kernel: [139267.057429] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 00 03 16 ef c8 00 00 00 80 00 00
Oct 12 23:23:43 proxmox-1 kernel: [139267.057447] scsi host6: uas_eh_bus_reset_handler start
Oct 12 23:23:44 proxmox-1 pvestatd[1331]: status update time (31.406 seconds)
Oct 12 23:24:05 proxmox-1 systemd-timesyncd[736]: interval/delta/delay/jitter/drift 2048s/+0.002s/0.009s/0.002s/-19ppm
Oct 12 23:24:19 proxmox-1 kernel: [139302.959665] sd 6:0:0:0: [sdb] tag#12 uas_eh_abort_handler 0 uas-tag 13 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.959674] sd 6:0:0:0: [sdb] tag#12 CDB: Write(16) 8a 00 00 00 00 00 e8 e3 c4 28 00 00 00 02 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.959825] sd 6:0:0:0: [sdb] tag#4 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.959831] sd 6:0:0:0: [sdb] tag#4 CDB: Write(16) 8a 00 00 00 00 00 03 2b 85 28 00 00 00 f0 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.959927] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.959932] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 03 2b 84 38 00 00 00 f0 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.959985] sd 6:0:0:0: [sdb] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.960178] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.960233] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:24:19 proxmox-1 kernel: [139302.960428] sd 6:0:0:0: [sdb] tag#11 CDB: Write(16) 8a 00 00 00 00 00 03 2b 80 e8 00 00 00 f0 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.960697] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 03 2b 7f 08 00 00 00 f0 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.960937] sd 6:0:0:0: [sdb] tag#7 CDB: Write(16) 8a 00 00 00 00 00 03 2b 7d 28 00 00 00 f0 00 00
Oct 12 23:24:19 proxmox-1 kernel: [139302.961188] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 00 03 2b 7b 48 00 00 00 f0 00 00
Oct 12 23:24:20 proxmox-1 pvestatd[1331]: status update time (25.431 seconds)
Oct 12 23:24:50 proxmox-1 kernel: [139334.001012] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 03 2d 9d 98 00 00 00 f0 00 00
Oct 12 23:24:50 proxmox-1 kernel: [139334.001258] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight:
Oct 12 23:24:50 proxmox-1 kernel: [139334.001327] scsi host6: uas_eh_bus_reset_handler start
Oct 12 23:24:50 proxmox-1 pvestatd[1331]: status update time (30.785 seconds)
Oct 12 23:25:21 proxmox-1 kernel: [139365.049469] scsi host6: uas_eh_bus_reset_handler success
Oct 12 23:25:22 proxmox-1 pvestatd[1331]: status update time (31.187 seconds)
Oct 12 23:25:57 proxmox-1 kernel: [139401.007178] sd 6:0:0:0: [sdb] tag#12 CDB: Write(16) 8a 00 00 00 00 00 e8 e3 c4 38 00 00 00 02 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.007443] sd 6:0:0:0: [sdb] tag#7 CDB: Write(16) 8a 00 00 00 00 00 03 43 a7 38 00 00 00 f0 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.007693] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 00 03 43 a5 58 00 00 00 f0 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.007938] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 03 43 a3 e8 00 00 00 f0 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.008201] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 03 43 a2 08 00 00 00 f0 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.008452] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 03 43 a0 28 00 00 00 f0 00 00
Oct 12 23:25:57 proxmox-1 kernel: [139401.008704] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 03 43 9e 48 00 00 00 f0 00 00
Oct 12 23:25:58 proxmox-1 pvestatd[1331]: status update time (25.730 seconds)
Oct 12 23:26:43 proxmox-1 kernel: [139447.022913] sd 6:0:0:0: [sdb] tag#5 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD OUT
Oct 12 23:26:43 proxmox-1 kernel: [139447.023011] sd 6:0:0:0: [sdb] tag#4 CDB: Write(16) 8a 00 00 00 00 00 03 79 84 28 00 00 00 f0 00 00
Oct 12 23:26:43 proxmox-1 kernel: [139447.023208] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 03 79 82 48 00 00 00 f0 00 00
Oct 12 23:26:43 proxmox-1 kernel: [139447.023454] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 03 79 80 68 00 00 00 f0 00 00
Oct 12 23:26:43 proxmox-1 kernel: [139447.023894] sd 6:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Oct 12 23:26:43 proxmox-1 kernel: [139447.024147] sd 6:0:0:0: [sdb] tag#7 CDB: Write(16) 8a 00 00 00 00 00 03 79 7c 28 00 00 00 f0 00 00
Oct 12 23:26:43 proxmox-1 kernel: [139447.136073] usb 10-2: reset SuperSpeed USB device number 2 using xhci_hcd
Oct 12 23:26:44 proxmox-1 pvestatd[1331]: status update time (26.206 seconds)
Oct 12 23:27:16 proxmox-1 kernel: [139479.919759] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 00 03 83 6c e8 00 00 00 f0 00 00
Oct 12 23:27:16 proxmox-1 kernel: [139479.920006] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
Oct 12 23:27:16 proxmox-1 kernel: [139479.920054] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 00 03 83 6a 18 00 00 00 f0 00 00
Oct 12 23:27:17 proxmox-1 pvestatd[1331]: status update time (22.522 seconds)
Oct 12 23:27:48 proxmox-1 pvestatd[1331]: status update time (30.939 seconds)
Oct 12 23:28:21 proxmox-1 kernel: [139544.943664] sd 6:0:0:0: [sdb] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
Oct 12 23:28:21 proxmox-1 kernel: [139544.943885] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:28:21 proxmox-1 kernel: [139544.943956] sd 6:0:0:0: [sdb] tag#10 CDB: Write(16) 8a 00 00 00 00 00 03 93 0a e0 00 00 00 f0 00 00
Oct 12 23:28:22 proxmox-1 pvestatd[1331]: status update time (23.762 seconds)
Oct 12 23:28:53 proxmox-1 kernel: [139576.946236] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.946245] sd 6:0:0:0: [sdb] tag#3 CDB: Write(16) 8a 00 00 00 00 00 03 99 82 50 00 00 00 f0 00 00
Oct 12 23:28:53 proxmox-1 kernel: [139576.946456] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.946554] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.946658] sd 6:0:0:0: [sdb] tag#11 uas_eh_abort_handler 0 uas-tag 12 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.946802] sd 6:0:0:0: [sdb] tag#10 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.946856] sd 6:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.947074] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 00 03 99 7d 20 00 00 00 80 00 00
Oct 12 23:28:53 proxmox-1 kernel: [139576.947315] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
Oct 12 23:28:53 proxmox-1 kernel: [139576.947440] sd 6:0:0:0: [sdb] tag#5 CDB: Write(16) 8a 00 00 00 00 00 03 99 7a 50 00 00 00 f0 00 00
Oct 12 23:28:53 proxmox-1 kernel: [139576.947692] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 03 99 78 70 00 00 00 f0 00 00
Oct 12 23:28:53 proxmox-1 kernel: [139577.059535] usb 10-2: reset SuperSpeed USB device number 2 using xhci_hcd
Oct 12 23:28:54 proxmox-1 pvestatd[1331]: status update time (21.582 seconds)

 

[manu]

reset SuperSpeed USB device number 2 ...

this klnd of errors happen and resetting happen when lowlevel commands USB/ATA are not answered in a timely manner by your USB or disk device
most probably a USB cable / device, the pve backup itself is probably fine, it's just that your target device does not allow writes ....

 

[Kharne]

The backup of all other machines work fine, the only difference is, that the second largest Backup takes roughly 55 GB.

The setup is the same for both servers: HDD Dockingstation, 4 TB WD Green, USB 3.0 Cable plugged directly into a USB 3.0 Port.

 

[Kharne]

Hi,

I´ve started the backupjob manually a few times yesterday, to see where it crashes. At first, it got stuck around 50GB written into the .tmp folder with a "reset SuperSpeed USB device number 2" error in the syslog. However, I could stop the backupjob and the server behaved normally afterwards.

In the third run, I got a "usb 10-2: device not accepting address 3, error -62" with a kernel message. Afterwards, the whole server was again stuck and had to be shutdown hard.

Spoiler: Syslog with Kernel message

Oct 17 14:29:12 proxmox-1 kernel: [55099.890217] usb 10-2: device not accepting address 3, error -62
Oct 17 14:30:53 proxmox-1 kernel: [55200.404426] [<ffffffff813cb3d9>] get_request+0x3f9/0x7a0
Oct 17 14:30:53 proxmox-1 kernel: [55200.404434] [<ffffffff813cc116>] submit_bio+0x76/0x180
Oct 17 14:30:53 proxmox-1 kernel: [55200.404494] [<ffffffff8119a5a3>] __writepage+0x13/0x30
Oct 17 14:30:53 proxmox-1 kernel: [55200.404515] [<ffffffffc0b8dc07>] xfs_vm_writepages+0x47/0x50 [xfs]
Oct 17 14:30:53 proxmox-1 kernel: [55200.404523] [<ffffffff8123fda2>] wb_writeback+0x272/0x300
Oct 17 14:30:53 proxmox-1 kernel: [55200.404531] [<ffffffff810a13aa>] kthread+0xfa/0x110
Oct 17 14:30:53 proxmox-1 kernel: [55200.405248] Tainted: P IO 4.4.76-1-pve #1
Oct 17 14:30:53 proxmox-1 kernel: [55200.406834] Call Trace:
Oct 17 14:30:53 proxmox-1 kernel: [55200.411931] ffff8801102b8000 ffff88061f3d7300 7fffffffffffffff ffff88032a36d940
Oct 17 14:30:53 proxmox-1 kernel: [55200.411941] [<ffffffff81861c55>] schedule+0x35/0x80
Oct 17 14:30:53 proxmox-1 kernel: [55200.411955] [<ffffffff8186114b>] io_schedule_timeout+0xbb/0x140
Oct 17 14:30:53 proxmox-1 kernel: [55200.411967] [<ffffffff8124b5e8>] blkdev_direct_IO+0x58/0x80
Oct 17 14:30:53 proxmox-1 kernel: [55200.411977] [<ffffffff8120f616>] vfs_read+0x86/0x130
Oct 17 14:32:43 proxmox-1 systemd-timesyncd[735]: interval/delta/delay/jitter/drift 2048s/-0.001s/0.013s/0.001s/-20ppm
Oct 17 14:32:53 proxmox-1 kernel: [55320.410613] INFO: task scsi_eh_15:6217 blocked for more than 120 seconds.
Oct 17 14:32:53 proxmox-1 kernel: [55320.411431] Tainted: P IO 4.4.76-1-pve #1
Oct 17 14:32:53 proxmox-1 kernel: [55320.412262] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 17 14:32:53 proxmox-1 kernel: [55320.413134] scsi_eh_15 D ffff880184bdf8a8 0 6217 2 0x00000000
Oct 17 14:32:53 proxmox-1 kernel: [55320.413137] ffff880184bdf8a8 ffff88041a3d1050 ffffffff81e12540 ffff880337342640
Oct 17 14:32:53 proxmox-1 kernel: [55320.413139] ffff880184be0000 ffff88041a3d1348 ffff880184bdf928 ffff880184bdf924
Oct 17 14:32:53 proxmox-1 kernel: [55320.413140] 0000000000000000 ffff880184bdf8c0 ffffffff81861c55 ffff880184bdf924
Oct 17 14:32:53 proxmox-1 kernel: [55320.413142] Call Trace:
Oct 17 14:32:53 proxmox-1 kernel: [55320.413148] [<ffffffff81861c55>] schedule+0x35/0x80
Oct 17 14:32:53 proxmox-1 kernel: [55320.413154] [<ffffffff81239f58>] wb_wait_for_completion+0x58/0xa0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413157] [<ffffffff810c4740>] ? wait_woken+0x90/0x90
Oct 17 14:32:53 proxmox-1 kernel: [55320.413160] [<ffffffff8123e004>] __writeback_inodes_sb_nr+0x94/0xe0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413161] [<ffffffff8123e097>] writeback_inodes_sb+0x27/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.413163] [<ffffffff812443ec>] sync_filesystem+0x2c/0xa0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413166] [<ffffffff8124c3c4>] fsync_bdev+0x24/0x50
Oct 17 14:32:53 proxmox-1 kernel: [55320.413169] [<ffffffff813dd0d4>] invalidate_partition+0x24/0x50
Oct 17 14:32:53 proxmox-1 kernel: [55320.413171] [<ffffffff813de14e>] del_gendisk+0xbe/0x270
Oct 17 14:32:53 proxmox-1 kernel: [55320.413173] [<ffffffff815d5301>] sd_remove+0x61/0xc0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413176] [<ffffffff81566406>] __device_release_driver+0x96/0x130
Oct 17 14:32:53 proxmox-1 kernel: [55320.413178] [<ffffffff815664c3>] device_release_driver+0x23/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.413179] [<ffffffff815651d1>] bus_remove_device+0x101/0x180
Oct 17 14:32:53 proxmox-1 kernel: [55320.413181] [<ffffffff815613b9>] device_del+0x139/0x270
Oct 17 14:32:53 proxmox-1 kernel: [55320.413185] [<ffffffff815cf69e>] __scsi_remove_device+0xce/0xe0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413187] [<ffffffff815cdba0>] scsi_forget_host+0x60/0x70
Oct 17 14:32:53 proxmox-1 kernel: [55320.413189] [<ffffffff815c1487>] scsi_remove_host+0x77/0x110
Oct 17 14:32:53 proxmox-1 kernel: [55320.413192] [<ffffffffc006ac75>] uas_disconnect+0x85/0xa0 [uas]
Oct 17 14:32:53 proxmox-1 kernel: [55320.413196] [<ffffffff81639136>] usb_unbind_interface+0x86/0x280
Oct 17 14:32:53 proxmox-1 kernel: [55320.413197] [<ffffffff81566406>] __device_release_driver+0x96/0x130
Oct 17 14:32:53 proxmox-1 kernel: [55320.413199] [<ffffffff815664c3>] device_release_driver+0x23/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.413201] [<ffffffff816393a7>] usb_driver_release_interface+0x77/0x80
Oct 17 14:32:53 proxmox-1 kernel: [55320.413202] [<ffffffff816393de>] usb_forced_unbind_intf+0x2e/0x60
Oct 17 14:32:53 proxmox-1 kernel: [55320.413204] [<ffffffff81639460>] unbind_marked_interfaces.isra.10+0x50/0x70
Oct 17 14:32:53 proxmox-1 kernel: [55320.413206] [<ffffffff816395a9>] usb_unbind_and_rebind_marked_interfaces+0x19/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.413207] [<ffffffff8162b2b6>] usb_reset_device+0x1c6/0x2a0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413209] [<ffffffffc006ad41>] uas_eh_bus_reset_handler+0xb1/0x190 [uas]
Oct 17 14:32:53 proxmox-1 kernel: [55320.413211] [<ffffffff815c2fe3>] scsi_try_bus_reset+0x43/0x100
Oct 17 14:32:53 proxmox-1 kernel: [55320.413213] [<ffffffff815c4b99>] scsi_eh_ready_devs+0x819/0xca0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413214] [<ffffffff815c64de>] scsi_error_handler+0x67e/0x8b0
Oct 17 14:32:53 proxmox-1 kernel: [55320.413216] [<ffffffff815c5e60>] ? scsi_eh_get_sense+0x250/0x250
Oct 17 14:32:53 proxmox-1 kernel: [55320.413218] [<ffffffff810a13aa>] kthread+0xfa/0x110
Oct 17 14:32:53 proxmox-1 kernel: [55320.413219] [<ffffffff810a12b0>] ? kthread_park+0x60/0x60
Oct 17 14:32:53 proxmox-1 kernel: [55320.413222] [<ffffffff8186610f>] ret_from_fork+0x3f/0x70
Oct 17 14:32:53 proxmox-1 kernel: [55320.413223] [<ffffffff810a12b0>] ? kthread_park+0x60/0x60
Oct 17 14:32:53 proxmox-1 kernel: [55320.413225] INFO: task kworker/u24:2:6220 blocked for more than 120 seconds.
Oct 17 14:32:53 proxmox-1 kernel: [55320.414103] Tainted: P IO 4.4.76-1-pve #1
Oct 17 14:32:53 proxmox-1 kernel: [55320.415048] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 17 14:32:53 proxmox-1 kernel: [55320.415953] kworker/u24:2 D ffff8801bd4c75c8 0 6220 2 0x00000000
Oct 17 14:32:53 proxmox-1 kernel: [55320.415958] Workqueue: writeback wb_workfn (flush-8:32)
Oct 17 14:32:53 proxmox-1 kernel: [55320.415959] ffff8801bd4c75c8 0000000000000200 ffff8806165fe600 ffff880184975940
Oct 17 14:32:53 proxmox-1 kernel: [55320.415961] ffff8801bd4c8000 ffff88061f217300 7fffffffffffffff ffff880184a10058
Oct 17 14:32:53 proxmox-1 kernel: [55320.415962] ffff880184a10000 ffff8801bd4c75e0 ffffffff81861c55 0000000000000000
Oct 17 14:32:53 proxmox-1 kernel: [55320.415963] Call Trace:
Oct 17 14:32:53 proxmox-1 kernel: [55320.415966] [<ffffffff81861c55>] schedule+0x35/0x80
Oct 17 14:32:53 proxmox-1 kernel: [55320.415967] [<ffffffff81864ea5>] schedule_timeout+0x235/0x2d0
Oct 17 14:32:53 proxmox-1 kernel: [55320.415971] [<ffffffff810f627b>] ? ktime_get+0x3b/0xb0
Oct 17 14:32:53 proxmox-1 kernel: [55320.415972] [<ffffffff8186114b>] io_schedule_timeout+0xbb/0x140
Oct 17 14:32:53 proxmox-1 kernel: [55320.415975] [<ffffffff813cb3d9>] get_request+0x3f9/0x7a0
Oct 17 14:32:53 proxmox-1 kernel: [55320.415977] [<ffffffff810c4740>] ? wait_woken+0x90/0x90
Oct 17 14:32:53 proxmox-1 kernel: [55320.415979] [<ffffffff813cdbb7>] blk_queue_bio+0xe7/0x3a0
Oct 17 14:32:53 proxmox-1 kernel: [55320.415980] [<ffffffff813cbf01>] generic_make_request+0x121/0x2c0
Oct 17 14:32:53 proxmox-1 kernel: [55320.415981] [<ffffffff813cc116>] submit_bio+0x76/0x180
Oct 17 14:32:53 proxmox-1 kernel: [55320.416013] [<ffffffffc0b8ce81>] xfs_submit_ioend_bio.isra.17+0x31/0x40 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.416027] [<ffffffffc0b8cf71>] xfs_submit_ioend+0xe1/0x120 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.416041] [<ffffffffc0b8d80e>] xfs_vm_writepage+0x2ae/0x660 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.416043] [<ffffffff8119a5a3>] __writepage+0x13/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.416045] [<ffffffff8119c9c8>] write_cache_pages+0x228/0x4e0
Oct 17 14:32:53 proxmox-1 kernel: [55320.416047] [<ffffffff8102d736>] ? __switch_to+0x256/0x5c0
Oct 17 14:32:53 proxmox-1 kernel: [55320.416048] [<ffffffff8119a590>] ? wb_position_ratio+0x1f0/0x1f0
Oct 17 14:32:53 proxmox-1 kernel: [55320.416050] [<ffffffff8119ccd1>] generic_writepages+0x51/0x80
Oct 17 14:32:53 proxmox-1 kernel: [55320.416064] [<ffffffffc0b8dc07>] xfs_vm_writepages+0x47/0x50 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.416066] [<ffffffff8119d92e>] do_writepages+0x1e/0x30
Oct 17 14:32:53 proxmox-1 kernel: [55320.416067] [<ffffffff8123ee75>] __writeback_single_inode+0x45/0x340
Oct 17 14:32:53 proxmox-1 kernel: [55320.416069] [<ffffffff8123f69c>] writeback_sb_inodes+0x27c/0x580
Oct 17 14:32:53 proxmox-1 kernel: [55320.416071] [<ffffffff8123fa29>] __writeback_inodes_wb+0x89/0xc0
Oct 17 14:32:53 proxmox-1 kernel: [55320.416072] [<ffffffff8123fda2>] wb_writeback+0x272/0x300
Oct 17 14:32:53 proxmox-1 kernel: [55320.416074] [<ffffffff8124054f>] wb_workfn+0x24f/0x400
Oct 17 14:32:53 proxmox-1 kernel: [55320.416076] [<ffffffff8109b278>] process_one_work+0x158/0x420
Oct 17 14:32:53 proxmox-1 kernel: [55320.416077] [<ffffffff8109bd59>] worker_thread+0x69/0x480
Oct 17 14:32:53 proxmox-1 kernel: [55320.416079] [<ffffffff8109bcf0>] ? rescuer_thread+0x330/0x330
Oct 17 14:32:53 proxmox-1 kernel: [55320.416080] [<ffffffff810a13aa>] kthread+0xfa/0x110
Oct 17 14:32:53 proxmox-1 kernel: [55320.416081] [<ffffffff810a12b0>] ? kthread_park+0x60/0x60
Oct 17 14:32:53 proxmox-1 kernel: [55320.416083] [<ffffffff8186610f>] ret_from_fork+0x3f/0x70
Oct 17 14:32:53 proxmox-1 kernel: [55320.416084] [<ffffffff810a12b0>] ? kthread_park+0x60/0x60
Oct 17 14:32:53 proxmox-1 kernel: [55320.416087] INFO: task xfsaild/sdc1:7987 blocked for more than 120 seconds.
Oct 17 14:32:53 proxmox-1 kernel: [55320.416998] Tainted: P IO 4.4.76-1-pve #1
Oct 17 14:32:53 proxmox-1 kernel: [55320.418998] [<ffffffffc0bb7b56>] xfs_log_force+0x26/0x90 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425345] du D ffff880214cbfa28 0 4538 28823 0x00000000
Oct 17 14:32:53 proxmox-1 kernel: [55320.425350] ffff880171342240 ffff880214cbfa40 ffffffff81861c55 7fffffffffffffff
Oct 17 14:32:53 proxmox-1 kernel: [55320.425356] [<ffffffff81861c55>] schedule+0x35/0x80
Oct 17 14:32:53 proxmox-1 kernel: [55320.425384] [<ffffffffc0b5d307>] ? xfs_bmap_search_multi_extents+0xb7/0x140 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425415] [<ffffffffc0b94a65>] ? _xfs_buf_find+0x165/0x370 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425446] [<ffffffffc0b94a65>] _xfs_buf_find+0x165/0x370 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425492] [<ffffffffc0bc3e13>] xfs_trans_read_buf_map+0xf3/0x310 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425548] [<ffffffffc0b97611>] xfs_readdir+0x181/0x1c0 [xfs]
Oct 17 14:32:53 proxmox-1 kernel: [55320.425569] [<ffffffff81223fa0>] ? iterate_dir+0x120/0x120
Oct 17 14:32:53 proxmox-1 kernel: [55320.428966] [<ffffffff813c78aa>] ? queue_unplugged+0x2a/0xb0
Oct 17 14:32:53 proxmox-1 kernel: [55320.428976] [<ffffffff812512b3>] __blockdev_direct_IO+0x43/0x50
Oct 17 14:32:53 proxmox-1 kernel: [55320.428985] [<ffffffff8120efd6>] __vfs_read+0x26/0x40

The automatic backup this night failed again, here we just see these two errors, followed by another kernel message

Oct 17 23:00:22 proxmox-1 systemd[1]: lxc@109.service: main process exited, code=exited, status=1/FAILURE
Oct 17 23:00:22 proxmox-1 systemd[1]: Unit lxc@109.service entered failed state.

Spoiler: Full Syslog

Oct 17 23:00:01 proxmox-1 CRON[550]: (root) CMD (vzdump 109 --compress lzo --mailnotification always --storage Proxmox-1_Backup --mailto me --quiet 1 --node proxmox-1 --mode stop)
Oct 17 23:00:01 proxmox-1 vzdump[553]: <root@pam> starting task UPIDroxmox-1:000002C1:0026BB4A:59E66F51:vzdump::root@pam:
Oct 17 23:00:01 proxmox-1 vzdump[705]: INFO: starting new backup job: vzdump 109 --quiet 1 --mode stop --storage Proxmox-1_Backup --mailnotification always --node proxmox-1 --compress lzo --mailto me
Oct 17 23:00:02 proxmox-1 vzdump[705]: INFO: Starting Backup of VM 109 (lxc)
Oct 17 23:00:20 proxmox-1 kernel: [25400.672959] vmbr0: port 4(veth109i0) entered disabled state
Oct 17 23:00:22 proxmox-1 systemd[1]: lxc@109.service: main process exited, code=exited, status=1/FAILURE
Oct 17 23:00:22 proxmox-1 systemd[1]: Unit lxc@109.service entered failed state.
Oct 17 23:03:11 proxmox-1 kernel: [25571.306269] sd 6:0:0:0: [sdb] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
Oct 17 23:03:11 proxmox-1 kernel: [25571.306275] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 65 88 3f ff 00 00 00 f0 00 00
Oct 17 23:03:11 proxmox-1 kernel: [25571.306514] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Oct 17 23:03:11 proxmox-1 kernel: [25571.306517] sd 6:0:0:0: [sdb] tag#1 CDB: Write(16) 8a 00 00 00 00 00 65 88 3f 0f 00 00 00 f0 00 00
Oct 17 23:03:11 proxmox-1 kernel: [25571.306775] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 65 88 3e 1f 00 00 00 f0 00 00
Oct 17 23:03:11 proxmox-1 kernel: [25571.307015] sd 6:0:0:0: [sdb] tag#11 CDB: Write(16) 8a 00 00 00 00 00 65 88 3d 2f 00 00 00 f0 00 00
Oct 17 23:03:11 proxmox-1 kernel: [25571.307508] sd 6:0:0:0: [sdb] tag#9 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
Oct 17 23:03:11 proxmox-1 kernel: [25571.307760] sd 6:0:0:0: [sdb] tag#7 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
Oct 17 23:03:11 proxmox-1 kernel: [25571.308059] sd 6:0:0:0: [sdb] tag#5 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD OUT
Oct 17 23:03:11 proxmox-1 kernel: [25571.308229] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight:
Oct 17 23:03:11 proxmox-1 kernel: [25571.444630] scsi host6: uas_eh_bus_reset_handler success
Oct 17 23:03:12 proxmox-1 pvestatd[1329]: status update time (21.754 seconds)
Oct 17 23:03:12 proxmox-1 kernel: [25572.406150] unregister_netdevice: waiting for lo to become free. Usage count = 1
Oct 17 23:11:03 proxmox-1 kernel: [26043.287930] sd 6:0:0:0: [sdb] tag#11 uas_eh_abort_handler 0 uas-tag 12 inflight: CMD OUT
Oct 17 23:11:03 proxmox-1 kernel: [26043.288420] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 79 28 95 67 00 00 00 58 00 00
Oct 17 23:11:03 proxmox-1 kernel: [26043.288674] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 7 inflight:
Oct 17 23:11:34 proxmox-1 kernel: [26074.268942] scsi host6: uas_eh_bus_reset_handler start
Oct 17 23:11:34 proxmox-1 kernel: [26074.270632] sd 6:0:0:0: [sdb] tag#4 CDB: Synchronize Cache(10) 35 00 00 00 00 00 00 00 00 00
Oct 17 23:11:35 proxmox-1 pvestatd[1329]: status update time (52.584 seconds)
Oct 17 23:12:15 proxmox-1 kernel: [26115.265826] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 79 53 21 bf 00 00 00 f0 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.266360] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 00 79 53 1f df 00 00 00 f0 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.266784] sd 6:0:0:0: [sdb] tag#6 CDB: Write(16) 8a 00 00 00 00 00 79 53 1d ff 00 00 00 f0 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.267072] sd 6:0:0:0: [sdb] tag#4 CDB: Write(16) 8a 00 00 00 00 00 79 53 1c 1f 00 00 00 f0 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.267520] sd 6:0:0:0: [sdb] tag#2 CDB: Write(16) 8a 00 00 00 00 00 79 53 1a af 00 00 00 80 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.267578] sd 6:0:0:0: [sdb] tag#9 CDB: Write(16) 8a 00 00 00 00 00 79 53 18 cf 00 00 00 f0 00 00
Oct 17 23:12:15 proxmox-1 kernel: [26115.267639] scsi host6: uas_eh_bus_reset_handler start
Oct 17 23:12:16 proxmox-1 pvestatd[1329]: status update time (30.838 seconds)
Oct 17 23:12:47 proxmox-1 kernel: [26147.263263] sd 6:0:0:0: [sdb] tag#10 CDB: Write(16) 8a 00 00 00 00 00 79 54 95 17 00 00 00 f0 00 00
Oct 17 23:12:47 proxmox-1 kernel: [26147.263785] sd 6:0:0:0: [sdb] tag#8 CDB: Write(16) 8a 00 00 00 00 00 79 54 93 37 00 00 00 f0 00 00
Oct 17 23:12:47 proxmox-1 kernel: [26147.264054] sd 6:0:0:0: [sdb] tag#6 CDB: Write(16) 8a 00 00 00 00 00 79 54 91 c7 00 00 00 f0 00 00
Oct 17 23:12:47 proxmox-1 kernel: [26147.264370] sd 6:0:0:0: [sdb] tag#4 CDB: Write(16) 8a 00 00 00 00 00 79 54 8f e7 00 00 00 f0 00 00
Oct 17 23:12:47 proxmox-1 kernel: [26147.264751] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
Oct 17 23:12:47 proxmox-1 kernel: [26147.265094] sd 6:0:0:0: [sdb] tag#0 CDB: Write(16) 8a 00 00 00 00 00 79 54 8c 27 00 00 00 f0 00 00
Oct 17 23:13:31 proxmox-1 kernel: [26190.980072] xhci_hcd 0000:01:00.0: Timeout while waiting for setup device command
Oct 17 23:13:31 proxmox-1 kernel: [26191.183895] usb 10-2: device not accepting address 2, error -62
Oct 17 23:14:58 proxmox-1 kernel: [26278.697391] INFO: task xfsaild/sdb1:28666 blocked for more than 120 seconds.
Oct 17 23:14:58 proxmox-1 kernel: [26278.698264] Tainted: P IO 4.4.83-1-pve #1
Oct 17 23:14:58 proxmox-1 kernel: [26278.699083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 17 23:14:58 proxmox-1 kernel: [26278.699919] xfsaild/sdb1 D ffff8803834b3d28 0 28666 2 0x00000000
Oct 17 23:14:58 proxmox-1 kernel: [26278.699922] ffff8803834b3d28 ffff88035cd26c00 ffff88061bb38cc0 ffff880615b55940
Oct 17 23:14:58 proxmox-1 kernel: [26278.699923] ffff8803834b4000 0000000000000000 ffff88035cd26c00 ffff88035cd26d28
Oct 17 23:14:58 proxmox-1 kernel: [26278.699925] ffff8803871ef300 ffff8803834b3d40 ffffffff81862d75 ffff880481b27800
Oct 17 23:14:58 proxmox-1 kernel: [26278.699926] Call Trace:
Oct 17 23:14:58 proxmox-1 kernel: [26278.699933] [<ffffffff81862d75>] schedule+0x35/0x80
Oct 17 23:14:58 proxmox-1 kernel: [26278.699963] [<ffffffffc0c1ba71>] _xfs_log_force+0x161/0x2c0 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.699966] [<ffffffff810acfb0>] ? wake_up_q+0x70/0x70
Oct 17 23:14:58 proxmox-1 kernel: [26278.699982] [<ffffffffc0c1bbf6>] xfs_log_force+0x26/0x90 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.699998] [<ffffffffc0c26bb7>] xfsaild+0x197/0x740 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.700000] [<ffffffff8102d736>] ? __switch_to+0x256/0x5c0
Oct 17 23:14:58 proxmox-1 kernel: [26278.700016] [<ffffffffc0c26a20>] ? xfs_trans_ail_cursor_first+0x90/0x90 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.700032] [<ffffffffc0c26a20>] ? xfs_trans_ail_cursor_first+0x90/0x90 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.700034] [<ffffffff810a13da>] kthread+0xfa/0x110
Oct 17 23:14:58 proxmox-1 kernel: [26278.700035] [<ffffffff810a12e0>] ? kthread_park+0x60/0x60
Oct 17 23:14:58 proxmox-1 kernel: [26278.700038] [<ffffffff8186724f>] ret_from_fork+0x3f/0x70
Oct 17 23:14:58 proxmox-1 kernel: [26278.700039] [<ffffffff810a12e0>] ? kthread_park+0x60/0x60
Oct 17 23:14:58 proxmox-1 kernel: [26278.700109] INFO: task kworker/u24:4:1014 blocked for more than 120 seconds.
Oct 17 23:14:58 proxmox-1 kernel: [26278.700933] Tainted: P IO 4.4.83-1-pve #1
Oct 17 23:14:58 proxmox-1 kernel: [26278.701814] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 17 23:14:58 proxmox-1 kernel: [26278.702690] kworker/u24:4 D ffff8804846db5c8 0 1014 2 0x00000000
Oct 17 23:14:58 proxmox-1 kernel: [26278.702698] ffff8804846db5c8 0000000000000200 ffff880619d20cc0 ffff880105478cc0
Oct 17 23:14:58 proxmox-1 kernel: [26278.702700] ffff880615a88000 ffff8804846db5e0 ffffffff81862d75 0000000000000000
Oct 17 23:14:58 proxmox-1 kernel: [26278.702704] [<ffffffff81862d75>] schedule+0x35/0x80
Oct 17 23:14:58 proxmox-1 kernel: [26278.702709] [<ffffffff810f631b>] ? ktime_get+0x3b/0xb0
Oct 17 23:14:58 proxmox-1 kernel: [26278.702713] [<ffffffff813cc2a9>] get_request+0x3f9/0x7a0
Oct 17 23:14:58 proxmox-1 kernel: [26278.702719] [<ffffffff813cea87>] blk_queue_bio+0xe7/0x3a0
Oct 17 23:14:58 proxmox-1 kernel: [26278.702737] [<ffffffffc0bf0e71>] xfs_submit_ioend_bio.isra.18+0x31/0x40 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.702768] [<ffffffff8119a5a3>] __writepage+0x13/0x30
Oct 17 23:14:58 proxmox-1 kernel: [26278.702773] [<ffffffff8119ccd1>] generic_writepages+0x51/0x80
Oct 17 23:14:58 proxmox-1 kernel: [26278.702791] [<ffffffffc0bf1bf7>] xfs_vm_writepages+0x47/0x50 [xfs]
Oct 17 23:14:58 proxmox-1 kernel: [26278.702797] [<ffffffff8124019c>] writeback_sb_inodes+0x27c/0x580
Oct 17 23:14:58 proxmox-1 kernel: [26278.702801] [<ffffffff8124104f>] wb_workfn+0x24f/0x400
Oct 17 23:14:58 proxmox-1 kernel: [26278.702806] [<ffffffff8109bd20>] ? rescuer_thread+0x330/0x330
Oct 17 23:14:58 proxmox-1 kernel: [26278.702810] [<ffffffff810a12e0>] ? kthread_park+0x60/0x60
Oct 17 23:14:58 proxmox-1 kernel: [26278.702816] INFO: task vgs:3394 blocked for more than 120 seconds.
Oct 17 23:14:58 proxmox-1 kernel: [26278.704522] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct 17 23:14:58 proxmox-1 kernel: [26278.705423] ffff880109d0b9e8 ffff880615a88000 ffff88061bb3cc80 ffff8800c27b72c0
Oct 17 23:14:58 proxmox-1 kernel: [26278.705438] ffff880109d0c000 ffff88061f3d7340 7fffffffffffffff ffff8800c27b72c0
Oct 17 23:14:58 proxmox-1 kernel: [26278.705440] ffff880615564a00 ffff880109d0ba00 ffffffff81862d75 0000000000000000
Oct 17 23:14:58 proxmox-1 kernel: [26278.705442] Call Trace:
Oct 17 23:14:58 proxmox-1 kernel: [26278.705445] [<ffffffff81862d75>] schedule+0x35/0x80
Oct 17 23:14:58 proxmox-1 kernel: [26278.705448] [<ffffffff81865fc5>] schedule_timeout+0x235/0x2d0
Oct 17 23:14:58 proxmox-1 kernel: [26278.705455] [<ffffffff813c877a>] ? queue_unplugged+0x2a/0xb0
Oct 17 23:14:58 proxmox-1 kernel: [26278.705462] [<ffffffff81250f1c>] do_blockdev_direct_IO+0x1b1c/0x2be0
Oct 17 23:14:58 proxmox-1 kernel: [26278.705476] [<ffffffff81252023>] __blockdev_direct_IO+0x43/0x50
Oct 17 23:14:58 proxmox-1 kernel: [26278.705479] [<ffffffff8124c358>] blkdev_direct_IO+0x58/0x80
Oct 17 23:14:58 proxmox-1 kernel: [26278.705481] [<ffffffff81190c4e>] generic_file_read_iter+0x4ce/0x680
Oct 17 23:14:58 proxmox-1 kernel: [26278.705484] [<ffffffff8124c707>] blkdev_read_iter+0x37/0x40
Oct 17 23:14:58 proxmox-1 kernel: [26278.705490] [<ffffffff8120fa04>] new_sync_read+0x94/0xd0
Oct 17 23:16:58 proxmox-1 kernel: [26398.705066] [<ffffffff81865fc5>] schedule_timeout+0x235/0x2d0
Oct 17 23:16:58 proxmox-1 kernel: [26398.705079] [<ffffffff810c47e0>] ? wait_woken+0x90/0x90
Oct 17 23:16:58 proxmox-1 kernel: [26398.705110] [<ffffffffc0bf0e71>] xfs_submit_ioend_bio.isra.18+0x31/0x40 [xfs]
Oct 17 23:16:58 proxmox-1 kernel: [26398.705169] [<ffffffffc0bf17fe>] xfs_vm_writepage+0x2ae/0x660 [xfs]
Oct 17 23:16:58 proxmox-1 kernel: [26398.705176] [<ffffffff8119a5a3>] __writepage+0x13/0x30
Oct 17 23:16:58 proxmox-1 kernel: [26398.705181] [<ffffffff8119c9c8>] write_cache_pages+0x228/0x4e0
Oct 17 23:16:58 proxmox-1 kernel: [26398.705184] [<ffffffff8119a590>] ? wb_position_ratio+0x1f0/0x1f0
Oct 17 23:16:58 proxmox-1 kernel: [26398.705188] [<ffffffff8119ccd1>] generic_writepages+0x51/0x80
Oct 17 23:16:58 proxmox-1 kernel: [26398.711003] [<ffffffff813c877a>] ? queue_unplugged+0x2a/0xb0
Oct 17 23:16:58 proxmox-1 kernel: [26398.711011] [<ffffffff8124bc50>] ? I_BDEV+0x20/0x20
Oct 17 23:16:58 proxmox-1 kernel: [26398.711017] [<ffffffff81190c4e>] generic_file_read_iter+0x4ce/0x680
Oct 17 23:16:58 proxmox-1 kernel: [26398.711023] [<ffffffff8120fa66>] __vfs_read+0x26/0x40
Oct 17 23:16:58 proxmox-1 kernel: [26398.711028] [<ffffffff81866eb6>] entry_SYSCALL_64_fastpath+0x16/0x75
Oct 17 23:17:01 proxmox-1 CRON[3687]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)
Oct 17 23:18:58 proxmox-1 kernel: [26518.702987] [<ffffffff810a12e0>] ? kthread_park+0x60/0x60
Oct 17 23:18:58 proxmox-1 kernel: [26518.704183] Tainted: P IO 4.4.83-1-pve #1
Oct 17 23:18:58 proxmox-1 kernel: [26518.706537] [<ffffffff81862d75>] schedule+0x35/0x80
Oct 17 23:18:58 proxmox-1 kernel: [26518.706543] [<ffffffff810abf99>] ? ttwu_do_wakeup+0x19/0xe0
Oct 17 23:18:58 proxmox-1 kernel: [26518.706547] [<ffffffff810acfb0>] ? wake_up_q+0x70/0x70
Oct 17 23:18:58 proxmox-1 kernel: [26518.706570] [<ffffffff810b8294>] ? dequeue_entity+0x414/0x9f0
Oct 17 23:18:58 proxmox-1 kernel: [26518.706620] [<ffffffffc0c1bc84>] xfs_log_worker+0x24/0x50 [xfs]
Oct 17 23:18:58 proxmox-1 kernel: [26518.706630] [<ffffffff8109bd20>] ? rescuer_thread+0x330/0x330
Oct 17 23:18:58 proxmox-1 kernel: [26518.706635] [<ffffffff810a12e0>] ? kthread_park+0x60/0x60
Oct 17 23:20:54 proxmox-1 systemd-timesyncd[736]: interval/delta/delay/jitter/drift 2048s/+0.001s/0.023s/0.002s/-21ppm

Do you have any ideas what is going wrong here?

 

[Kharne]

So as a last measure, we switched the machines. Booted proxmox-1 on server 2 and vice versa. Turns out the Backup of VM-109 works flawlessly and finishes now under 1 hour, while proxmox-2 couldn´t mount the backup drive on the usually used USB 3.0 ports. I guess the board in this server is dying...

Anyway, thanks for the help!