Backup: Job failed with err -5 - Input/output error
- Thread starter arky_
- Start date
Hi,
please share the full task log for the backup job. I/O errors typically indicate an issue with the underlying storage, so also check the smart values of the disks and check the systemd journal for error messages around the time when the backup happens. You can dump the journal for the corresponding time frame via
please share the full task log for the backup job. I/O errors typically indicate an issue with the underlying storage, so also check the smart values of the disks and check the systemd journal for error messages around the time when the backup happens. You can dump the journal for the corresponding time frame via
journalctl --since <DATETIME> --until <DATETIME> > journal.txtHi, here are the logs from when the backup was created. I don't really understand what it says and what the problem is. Can I ask for help finding the problem?
Code:
-- Journal begins at Sun 2024-01-21 23:35:01 CET, ends at Fri 2024-05-17 15:54:25 CEST. --
May 17 15:27:25 proxmox1 sshd[3287291]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:27:25 proxmox1 sshd[3287291]: Connection closed by 10.0.0.121 port 53190
May 17 15:27:28 proxmox1 pvedaemon[3506511]: <root@pam> starting task UPID:proxmox1:0032291D:CAD8B15B:66475B40:vzdump:108:root@pam:
May 17 15:27:28 proxmox1 pvedaemon[3287325]: INFO: starting new backup job: vzdump 108 --compress zstd --mode snapshot --storage local --node proxmox1 --notes-template '{{guestname}}' --remove 0
May 17 15:27:28 proxmox1 pvedaemon[3287325]: INFO: Starting Backup of VM 108 (qemu)
May 17 15:27:40 proxmox1 sshd[3313738]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:27:40 proxmox1 sshd[3313738]: Connection closed by 10.0.0.121 port 53198
May 17 15:27:55 proxmox1 sshd[3342019]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:27:55 proxmox1 sshd[3342019]: Connection closed by 10.0.0.121 port 53208
May 17 15:28:06 proxmox1 sshd[3359499]: Accepted publickey for root from 10.0.0.211 port 52259 ssh2: RSA SHA256:8DydAHDrNGJsv7YH7Tr6iHJAWKKwBmV4N2uWYxqr2so
May 17 15:28:06 proxmox1 sshd[3359499]: pam_unix(sshd:session): session opened for user root(uid=0) by (uid=0)
May 17 15:28:06 proxmox1 systemd[1]: Created slice User Slice of UID 0.
May 17 15:28:06 proxmox1 systemd[1]: Starting User Runtime Directory /run/user/0...
May 17 15:28:06 proxmox1 systemd-logind[3992]: New session 63224 of user root.
May 17 15:28:06 proxmox1 systemd[1]: Finished User Runtime Directory /run/user/0.
May 17 15:28:06 proxmox1 systemd[1]: Starting User Manager for UID 0...
May 17 15:28:06 proxmox1 systemd[3360121]: pam_unix(systemd-user:session): session opened for user root(uid=0) by (uid=0)
May 17 15:28:06 proxmox1 systemd[3360121]: Queued start job for default target Main User Target.
May 17 15:28:06 proxmox1 systemd[3360121]: Created slice User Application Slice.
May 17 15:28:06 proxmox1 systemd[3360121]: Reached target Paths.
May 17 15:28:06 proxmox1 systemd[3360121]: Reached target Timers.
May 17 15:28:06 proxmox1 systemd[3360121]: Listening on GnuPG network certificate management daemon.
May 17 15:28:06 proxmox1 systemd[3360121]: Listening on GnuPG cryptographic agent and passphrase cache (access for web browsers).
May 17 15:28:06 proxmox1 systemd[3360121]: Listening on GnuPG cryptographic agent and passphrase cache (restricted).
May 17 15:28:06 proxmox1 systemd[3360121]: Listening on GnuPG cryptographic agent (ssh-agent emulation).
May 17 15:28:06 proxmox1 systemd[3360121]: Listening on GnuPG cryptographic agent and passphrase cache.
May 17 15:28:06 proxmox1 systemd[3360121]: Reached target Sockets.
May 17 15:28:06 proxmox1 systemd[3360121]: Reached target Basic System.
May 17 15:28:06 proxmox1 systemd[3360121]: Reached target Main User Target.
May 17 15:28:06 proxmox1 systemd[3360121]: Startup finished in 431ms.
May 17 15:28:06 proxmox1 systemd[1]: Started User Manager for UID 0.
May 17 15:28:06 proxmox1 systemd[1]: Started Session 63224 of user root.
May 17 15:28:10 proxmox1 sshd[3366068]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:28:10 proxmox1 sshd[3366068]: Connection closed by 10.0.0.121 port 53218
May 17 15:28:25 proxmox1 sshd[3375610]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:28:25 proxmox1 sshd[3375610]: Connection closed by 10.0.0.121 port 53228
May 17 15:28:40 proxmox1 sshd[3397988]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:28:40 proxmox1 sshd[3397988]: Connection closed by 10.0.0.121 port 53236
May 17 15:28:55 proxmox1 sshd[3414687]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:28:55 proxmox1 sshd[3414687]: Connection closed by 10.0.0.121 port 53246
May 17 15:29:10 proxmox1 sshd[3430115]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:29:10 proxmox1 sshd[3430115]: Connection closed by 10.0.0.121 port 53254
May 17 15:29:25 proxmox1 sshd[3439311]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:29:25 proxmox1 sshd[3439311]: Connection closed by 10.0.0.121 port 53263
May 17 15:29:40 proxmox1 sshd[3456535]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:29:40 proxmox1 sshd[3456535]: Connection closed by 10.0.0.121 port 53276
May 17 15:29:55 proxmox1 sshd[3471877]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:29:55 proxmox1 sshd[3471877]: Connection closed by 10.0.0.121 port 53283
May 17 15:30:10 proxmox1 sshd[3494677]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:30:10 proxmox1 sshd[3494677]: Connection closed by 10.0.0.121 port 53289
May 17 15:30:25 proxmox1 sshd[3516223]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:30:25 proxmox1 sshd[3516223]: Connection closed by 10.0.0.121 port 53302
May 17 15:30:40 proxmox1 sshd[3547117]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:30:40 proxmox1 sshd[3547117]: Connection closed by 10.0.0.121 port 53308
May 17 15:30:45 proxmox1 postfix/qmgr[4374]: D8203205386: from=<>, size=11873, nrcpt=1 (queue active)
May 17 15:30:45 proxmox1 postfix/qmgr[4374]: 64FD5206688: from=<>, size=11853, nrcpt=1 (queue active)
May 17 15:30:45 proxmox1 postfix/local[3555314]: error: open database /etc/aliases.db: No such file or directory
May 17 15:30:45 proxmox1 postfix/local[3555314]: warning: hash:/etc/aliases is unavailable. open database /etc/aliases.db: No such file or directory
May 17 15:30:45 proxmox1 postfix/local[3555314]: warning: hash:/etc/aliases: lookup of 'root' failed
May 17 15:30:45 proxmox1 postfix/local[3555319]: error: open database /etc/aliases.db: No such file or directory
May 17 15:30:45 proxmox1 postfix/local[3555319]: warning: hash:/etc/aliases is unavailable. open database /etc/aliases.db: No such file or directory
May 17 15:30:45 proxmox1 postfix/local[3555319]: warning: hash:/etc/aliases: lookup of 'root' failed
May 17 15:30:45 proxmox1 postfix/local[3555314]: D8203205386: to=<root@proxmox1.psk-net.pl>, relay=local, delay=424712, delays=424712/0.02/0/0.13, dsn=4.3.0, status=deferred (alias database unavailable)
May 17 15:30:45 proxmox1 postfix/local[3555319]: 64FD5206688: to=<root@proxmox1.psk-net.pl>, relay=local, delay=210598, delays=210598/0.02/0/0.15, dsn=4.3.0, status=deferred (alias database unavailable)
May 17 15:30:55 proxmox1 sshd[3579229]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:30:55 proxmox1 sshd[3579229]: Connection closed by 10.0.0.121 port 53319
May 17 15:31:10 proxmox1 sshd[3605713]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:31:10 proxmox1 sshd[3605713]: Connection closed by 10.0.0.121 port 53330
May 17 15:31:25 proxmox1 sshd[3634124]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:31:25 proxmox1 sshd[3634124]: Connection closed by 10.0.0.121 port 53342
May 17 15:31:33 proxmox1 pvedaemon[3506511]: worker exit
May 17 15:31:33 proxmox1 pvedaemon[4425]: worker 3506511 finished
May 17 15:31:33 proxmox1 pvedaemon[4425]: starting 1 worker(s)
May 17 15:31:33 proxmox1 pvedaemon[4425]: worker 3645512 started
May 17 15:31:40 proxmox1 sshd[3646599]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:31:40 proxmox1 sshd[3646599]: Connection closed by 10.0.0.121 port 53350
May 17 15:31:43 proxmox1 kernel: sas: Enter sas_scsi_recover_host busy: 1 failed: 1
May 17 15:31:43 proxmox1 kernel: sas: ata9: end_device-0:2: cmd error handler
May 17 15:31:43 proxmox1 kernel: sas: ata7: end_device-0:0: dev error handler
May 17 15:31:43 proxmox1 kernel: sas: ata8: end_device-0:1: dev error handler
May 17 15:31:43 proxmox1 kernel: sas: ata9: end_device-0:2: dev error handler
May 17 15:31:43 proxmox1 kernel: ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
May 17 15:31:43 proxmox1 kernel: ata9.00: failed command: READ DMA EXT
May 17 15:31:43 proxmox1 kernel: ata9.00: cmd 25/00:20:f8:e8:65/00:00:4d:00:00/e0 tag 30 dma 16384 in
res 51/40:20:f8:e8:65/00:00:4d:00:00/e0 Emask 0x9 (media error)
May 17 15:31:43 proxmox1 kernel: ata9.00: status: { DRDY ERR }
May 17 15:31:43 proxmox1 kernel: ata9.00: error: { UNC }
May 17 15:31:43 proxmox1 kernel: ata9.00: configured for UDMA/133
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#196 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#196 Sense Key : Medium Error [current]
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#196 Add. Sense: Unrecovered read error - auto reallocate failed
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#196 CDB: Read(10) 28 00 4d 65 e8 f8 00 00 20 00
May 17 15:31:43 proxmox1 kernel: blk_update_request: I/O error, dev sdc, sector 1298524408 op 0x0:(READ) flags 0x700 phys_seg 2 prio class 0
May 17 15:31:43 proxmox1 kernel: zio pool=rpool vdev=/dev/sdc1 error=5 type=1 offset=664843448320 size=8192 flags=180880
May 17 15:31:43 proxmox1 kernel: zio pool=rpool vdev=/dev/sdc1 error=5 type=1 offset=664843456512 size=8192 flags=180880
May 17 15:31:43 proxmox1 kernel: ata9: EH complete
May 17 15:31:43 proxmox1 kernel: sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 1 tries: 1
May 17 15:31:43 proxmox1 zed[3646679]: eid=222713 class=io pool='rpool' vdev=sdc1 size=8192 offset=664843456512 priority=0 err=5 flags=0x180880 delay=189ms bookmark=32310:1:0:8320311
May 17 15:31:43 proxmox1 zed[3646680]: eid=222714 class=io pool='rpool' vdev=sdc1 size=8192 offset=664843448320 priority=0 err=5 flags=0x180880 delay=189ms bookmark=32310:1:0:8320310
May 17 15:31:43 proxmox1 zed[3646682]: eid=222715 class=io pool='rpool' size=8192 offset=664839262208 priority=0 err=5 flags=0x100880 bookmark=32310:1:0:8320311
May 17 15:31:43 proxmox1 zed[3646684]: eid=222716 class=io pool='rpool' size=8192 offset=664839254016 priority=0 err=5 flags=0x100880 bookmark=32310:1:0:8320310
May 17 15:31:43 proxmox1 kernel: sas: Enter sas_scsi_recover_host busy: 1 failed: 1
May 17 15:31:43 proxmox1 kernel: sas: ata9: end_device-0:2: cmd error handler
May 17 15:31:43 proxmox1 kernel: sas: ata7: end_device-0:0: dev error handler
May 17 15:31:43 proxmox1 kernel: sas: ata8: end_device-0:1: dev error handler
May 17 15:31:43 proxmox1 kernel: sas: ata9: end_device-0:2: dev error handler
May 17 15:31:43 proxmox1 kernel: ata9.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
May 17 15:31:43 proxmox1 kernel: ata9.00: failed command: READ DMA EXT
May 17 15:31:43 proxmox1 kernel: ata9.00: cmd 25/00:10:f8:e8:65/00:00:4d:00:00/e0 tag 12 dma 8192 in
res 51/40:10:f8:e8:65/00:00:4d:00:00/e0 Emask 0x9 (media error)
May 17 15:31:43 proxmox1 kernel: ata9.00: status: { DRDY ERR }
May 17 15:31:43 proxmox1 kernel: ata9.00: error: { UNC }
May 17 15:31:43 proxmox1 kernel: ata9.00: configured for UDMA/133
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#167 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_OK cmd_age=0s
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#167 Sense Key : Medium Error [current]
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#167 Add. Sense: Unrecovered read error - auto reallocate failed
May 17 15:31:43 proxmox1 kernel: sd 0:0:2:0: [sdc] tag#167 CDB: Read(10) 28 00 4d 65 e8 f8 00 00 10 00
May 17 15:31:43 proxmox1 kernel: blk_update_request: I/O error, dev sdc, sector 1298524408 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
May 17 15:31:43 proxmox1 kernel: zio pool=rpool vdev=/dev/sdc1 error=5 type=1 offset=664843448320 size=8192 flags=188881
May 17 15:31:43 proxmox1 kernel: ata9: EH complete
May 17 15:31:43 proxmox1 kernel: sas: --- Exit sas_scsi_recover_host: busy: 0 failed: 1 tries: 1
May 17 15:31:43 proxmox1 zed[3646807]: eid=222717 class=data pool='rpool' priority=0 err=5 flags=0x8881 bookmark=32310:1:0:8320310
May 17 15:31:44 proxmox1 pvedaemon[3287325]: ERROR: Backup of VM 108 failed - job failed with err -5 - Input/output error
May 17 15:31:44 proxmox1 pvedaemon[3287325]: INFO: Backup job finished with errors
May 17 15:31:44 proxmox1 pvedaemon[3287325]: job errors
May 17 15:31:55 proxmox1 sshd[3649992]: error: kex_exchange_identification: Connection closed by remote host
May 17 15:31:55 proxmox1 sshd[3649992]: Connection closed by 10.0.0.121 port 53359Looks like the drive has bad sectors and cannot relocate these, please check the disks smart value and consider replacing it.
