Backup fails with interrupted by signal

[robhost]

Hi,

our PBS backups from PVE (both latest versions) are failing sometimes with "interrupted by signal" - but there is no further info in the logs, only this:

INFO: creating Proxmox Backup Server archive 'vm/5297/2021-02-25T22:30:00Z'
ERROR: Backup of VM 5297 failed - interrupted by signal
INFO: Failed at 2021-02-25 23:30:03
INFO: update VM 5297: -scsi0 ceph-vs:vm-5297-disk-0,cache=writeback,discard=on,iops_rd=200,iops_rd_max=3000,iops_wr=200,iops_wr_max=3000,size=100G -skiplock 1
ERROR: Backup job failed - interrupted by signal

TASK ERROR: interrupted by signal

Any idea what this is or how to fix this?

Thanks!

 

[Stoiko Ivanov]

anything in the system's (the pve-node or the pbs) journal while the backup gets terminated?

 

[robhost]

No - we will do another backup full-run and report back if the error comes up again.

 

[robhost]

Just happened again and killed the whole backup job, see attached image. Before it made 10 VM backups without problems./

INFO: update VM 5065: -scsi0 nvme0:5065/vm-5065-disk-0.qcow2,cache=writeback,discard=on,format=qcow2,size=250G,iops_rd=1000,iops_rd_max=15000,iops_wr=500,iops_wr_max=7500 -skiplock 1
INFO: creating Proxmox Backup Server archive 'vm/5065/2021-03-04T21:56:03Z'
ERROR: Backup of VM 5065 failed - interrupted by signal
INFO: Failed at 2021-03-04 22:56:04
INFO: update VM 5065: -scsi0 nvme0:5065/vm-5065-disk-0.qcow2,cache=writeback,discard=on,format=qcow2,iops_rd=1000,iops_rd_max=5000,iops_wr=1000,iops_wr_max=5000,size=250G -skiplock 1
ERROR: Backup job failed - interrupted by signal

Why does it not print which signal caused the interruption?

There is nothing in the logs on PBS regarding this VM, it seems PVE causes the problem (latest version):

Mar 04 22:56:03 hav203 vzdump[16324]: INFO: Starting Backup of VM 5065 (qemu)
Mar 04 22:56:04 hav203 vzdump[16324]: ERROR: Backup of VM 5065 failed - interrupted by signal
Mar 04 22:56:05 hav203 vzdump[16324]: ERROR: Backup job failed - interrupted by signal
Mar 04 22:56:05 hav203 vzdump[16324]: interrupted by signal
Mar 04 22:56:05 hav203 vzdump[16314]: <root@pam> end task UPID:hav203:00003FC4:D5594667:6041191A:vzdump::root@pam: interrupted by signal

 

[dcsapak]

is there more info in the syslog/journal on the pve side?

 

[robhost]

Nope, only the vzdump output from the last posting.

 

[robhost]

The problem persists, making PBS not usable so far
How to get further infos, why don't you print the signal number within the error?

 

[dcsapak]

what happens around that time the backups aborts in the logs?

interrupted by signal normally means either someone pressed 'stop', someone 'killed' the process, the kernel kills a process e.g. because of OOM or the process segfaults, all of which should be visible in the logs

 

[robhost]

There is nothing in the logs on the PVE host, no OOM and nothing else.

The ist the task log:

INFO: Starting Backup of VM 5242 (qemu)
INFO: Backup started at 2021-03-19 01:50:04
INFO: status = running
INFO: VM Name: vs5242
INFO: include disk 'scsi0' 'ceph-vs:vm-5242-disk-0' 250G
INFO: backup mode: snapshot
INFO: bandwidth limit: 80000 KB/s
INFO: ionice priority: 7
INFO: update VM 5242: -scsi0 ceph-vs:vm-5242-disk-0,cache=writeback,discard=on,size=250G,iops_rd=1000,iops_rd_max=15000,iops_wr=500,iops_wr_max=7500 -skiplock 1
INFO: creating Proxmox Backup Server archive 'vm/5242/2021-03-19T00:50:04Z'
ERROR: Backup of VM 5242 failed - interrupted by signal
INFO: Failed at 2021-03-19 01:50:06
INFO: update VM 5242: -scsi0 ceph-vs:vm-5242-disk-0,cache=writeback,discard=on,iops_rd=200,iops_rd_max=3000,iops_wr=200,iops_wr_max=3000,size=250G -skiplock 1
ERROR: Backup job failed - interrupted by signal

Also nothing on the PBS host in the logs.

Would be nice to get more informations why this happens :/

 

[dcsapak]

There is nothing in the logs on the PVE host, no OOM and nothing else.

can you post some portion of the logs (syslog/journal/dmesg) from that timeframe? maybe we are able to detect something?
otherwise there is really nothing we can do ...

 

[robhost]

There is nothing in there at this time, not even an entry

Can we expand logging or enable debug?

 

[robhost]

Okay, got something "strange" on the host:

 Mar 19 01:50:06 hav203 qmeventd[1346]: error parsing vmid for 31032: Success

We've got a hook script running which increases the VM IOPS during backups - maybe this causes the problem here?

 

[dcsapak]

We've got a hook script running which increases the VM IOPS during backups - maybe this causes the problem here?

maybe, how does it look like? can you post it? (anonymized of course)

 

[robhost]

maybe, how does it look like? can you post it? (anonymized of course)

Here you go: https://github.com/robhost/proxmox-scripts/blob/master/vzdump_hook.sh