PROBLEM: Can´t backup VMs anymore

S

sysadminfromhell

Member
Feb 3, 2022
65
6
13
28
Hey everyone,

after I had a IP double use (accidentally) I get errors while a backupjob,
The Log shows the following error:

storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Backup job finished with errors
TASK ERROR: job errors

The funny part is, that I only get the task error on one host.
On the other 2 Hosts the Backup job finished with errors but was OK:

storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Backup job finished successfully
TASK OK

I tried to recreate all credentials by using pvecm updatecerts as mentioned in a other similiar problem.

any help is appreciated.
Kind regards,
 
  • Like
Reactions: franko5
Ah yes, a colleague just hinted at this message always appearing now.
So the issue might be something else.

Please provide the complete task log of the backup job that failed. And the journal/syslog containing the whole time the job was running to see if there were some other issues during that time.
 
here is the Log of the task:

Code: 
Header
Proxmox
Virtual Environment 7.3-4
Search
Datacenter
Search:
Server View
Logs
INFO: starting new backup job: vzdump 101 102 104 109 105 106 110 --notes-template '{{guestname}}' --quiet 1 --mailto --mode snapshot --mailnotification failure --storage PBS01
INFO: skip external VMs: 101, 102, 104, 105
INFO: Starting Backup of VM 106 (qemu)
INFO: Backup started at 2023-01-04 08:00:02
INFO: status = running
INFO: VM Name: RMD
INFO: include disk 'scsi0' 'LUN2_1:vm-106-disk-1' 45G
INFO: include disk 'efidisk0' 'LUN2_1:vm-106-disk-0' 528K
INFO: include disk 'tpmstate0' 'LUN2_1:vm-106-disk-2' 4M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/106/2023-01-04T07:00:02Z'
INFO: attaching TPM drive to QEMU for backup
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '3bdcaaec-d737-4aef-816c-6d3b1f2fd348'
INFO: resuming VM again
INFO: efidisk0: dirty-bitmap status: OK (drive clean)
INFO: scsi0: dirty-bitmap status: OK (3.5 GiB of 45.0 GiB dirty)
INFO: tpmstate0-backup: dirty-bitmap status: created new
INFO: using fast incremental mode (dirty-bitmap), 3.5 GiB dirty of 45.0 GiB total
INFO:   0% (20.0 MiB of 3.5 GiB) in 3s, read: 6.7 MiB/s, write: 5.3 MiB/s
INFO:   2% (100.0 MiB of 3.5 GiB) in 6s, read: 26.7 MiB/s, write: 24.0 MiB/s
INFO:   4% (172.0 MiB of 3.5 GiB) in 9s, read: 24.0 MiB/s, write: 21.3 MiB/s
INFO:   6% (216.0 MiB of 3.5 GiB) in 12s, read: 14.7 MiB/s, write: 14.7 MiB/s
INFO:   7% (260.0 MiB of 3.5 GiB) in 16s, read: 11.0 MiB/s, write: 11.0 MiB/s
INFO:   9% (356.0 MiB of 3.5 GiB) in 19s, read: 32.0 MiB/s, write: 30.7 MiB/s
INFO:  13% (480.0 MiB of 3.5 GiB) in 22s, read: 41.3 MiB/s, write: 41.3 MiB/s
INFO:  14% (532.0 MiB of 3.5 GiB) in 25s, read: 17.3 MiB/s, write: 17.3 MiB/s
INFO:  16% (576.0 MiB of 3.5 GiB) in 28s, read: 14.7 MiB/s, write: 14.7 MiB/s
INFO:  18% (668.0 MiB of 3.5 GiB) in 31s, read: 30.7 MiB/s, write: 29.3 MiB/s
INFO:  20% (736.0 MiB of 3.5 GiB) in 34s, read: 22.7 MiB/s, write: 20.0 MiB/s
INFO:  21% (788.0 MiB of 3.5 GiB) in 37s, read: 17.3 MiB/s, write: 14.7 MiB/s
INFO:  22% (792.0 MiB of 3.5 GiB) in 51s, read: 292.6 KiB/s, write: 0 B/s
INFO:  23% (844.0 MiB of 3.5 GiB) in 59s, read: 6.5 MiB/s, write: 5.0 MiB/s
INFO:  24% (864.0 MiB of 3.5 GiB) in 1m 15s, read: 1.2 MiB/s, write: 1.2 MiB/s
INFO:  25% (928.0 MiB of 3.5 GiB) in 1m 18s, read: 21.3 MiB/s, write: 21.3 MiB/s
INFO:  27% (1000.0 MiB of 3.5 GiB) in 1m 21s, read: 24.0 MiB/s, write: 24.0 MiB/s
INFO:  31% (1.1 GiB of 3.5 GiB) in 1m 24s, read: 40.0 MiB/s, write: 38.7 MiB/s
INFO:  33% (1.2 GiB of 3.5 GiB) in 1m 27s, read: 22.7 MiB/s, write: 22.7 MiB/s
INFO:  35% (1.3 GiB of 3.5 GiB) in 1m 30s, read: 33.3 MiB/s, write: 29.3 MiB/s
INFO:  37% (1.3 GiB of 3.5 GiB) in 1m 33s, read: 13.3 MiB/s, write: 13.3 MiB/s
INFO:  38% (1.3 GiB of 3.5 GiB) in 1m 37s, read: 12.0 MiB/s, write: 10.0 MiB/s
INFO:  39% (1.4 GiB of 3.5 GiB) in 1m 49s, read: 2.3 MiB/s, write: 2.3 MiB/s
INFO:  40% (1.4 GiB of 3.5 GiB) in 1m 59s, read: 4.0 MiB/s, write: 4.0 MiB/s
INFO:  43% (1.5 GiB of 3.5 GiB) in 2m 2s, read: 34.7 MiB/s, write: 34.7 MiB/s
INFO:  44% (1.6 GiB of 3.5 GiB) in 2m 5s, read: 13.3 MiB/s, write: 13.3 MiB/s
INFO:  45% (1.6 GiB of 3.5 GiB) in 2m 9s, read: 11.0 MiB/s, write: 10.0 MiB/s
INFO:  47% (1.7 GiB of 3.5 GiB) in 2m 12s, read: 25.3 MiB/s, write: 24.0 MiB/s
INFO:  49% (1.7 GiB of 3.5 GiB) in 2m 15s, read: 20.0 MiB/s, write: 14.7 MiB/s
INFO:  50% (1.8 GiB of 3.5 GiB) in 2m 18s, read: 16.0 MiB/s, write: 16.0 MiB/s
INFO:  51% (1.8 GiB of 3.5 GiB) in 2m 25s, read: 4.0 MiB/s, write: 4.0 MiB/s
INFO:  52% (1.8 GiB of 3.5 GiB) in 2m 28s, read: 8.0 MiB/s, write: 8.0 MiB/s
INFO:  53% (1.9 GiB of 3.5 GiB) in 2m 35s, read: 5.7 MiB/s, write: 5.7 MiB/s
INFO:  54% (1.9 GiB of 3.5 GiB) in 2m 38s, read: 20.0 MiB/s, write: 17.3 MiB/s
INFO:  57% (2.0 GiB of 3.5 GiB) in 2m 41s, read: 32.0 MiB/s, write: 30.7 MiB/s
INFO:  58% (2.0 GiB of 3.5 GiB) in 2m 44s, read: 8.0 MiB/s, write: 5.3 MiB/s
INFO:  60% (2.1 GiB of 3.5 GiB) in 2m 47s, read: 26.7 MiB/s, write: 22.7 MiB/s
INFO:  61% (2.2 GiB of 3.5 GiB) in 2m 50s, read: 17.3 MiB/s, write: 14.7 MiB/s
INFO:  62% (2.2 GiB of 3.5 GiB) in 2m 53s, read: 13.3 MiB/s, write: 9.3 MiB/s
INFO:  64% (2.3 GiB of 3.5 GiB) in 2m 56s, read: 18.7 MiB/s, write: 13.3 MiB/s
INFO:  66% (2.3 GiB of 3.5 GiB) in 2m 59s, read: 20.0 MiB/s, write: 13.3 MiB/s
INFO:  69% (2.4 GiB of 3.5 GiB) in 3m 2s, read: 40.0 MiB/s, write: 40.0 MiB/s
INFO:  72% (2.6 GiB of 3.5 GiB) in 3m 5s, read: 38.7 MiB/s, write: 37.3 MiB/s
INFO:  74% (2.6 GiB of 3.5 GiB) in 3m 11s, read: 10.0 MiB/s, write: 9.3 MiB/s
INFO:  75% (2.6 GiB of 3.5 GiB) in 3m 14s, read: 9.3 MiB/s, write: 8.0 MiB/s
INFO:  76% (2.7 GiB of 3.5 GiB) in 3m 17s, read: 18.7 MiB/s, write: 18.7 MiB/s
INFO:  78% (2.7 GiB of 3.5 GiB) in 3m 20s, read: 14.7 MiB/s, write: 14.7 MiB/s
INFO:  79% (2.8 GiB of 3.5 GiB) in 3m 42s, read: 1.6 MiB/s, write: 1.5 MiB/s
INFO:  80% (2.8 GiB of 3.5 GiB) in 3m 45s, read: 20.0 MiB/s, write: 17.3 MiB/s
INFO:  81% (2.8 GiB of 3.5 GiB) in 3m 49s, read: 4.0 MiB/s, write: 4.0 MiB/s
INFO:  82% (2.9 GiB of 3.5 GiB) in 3m 52s, read: 12.0 MiB/s, write: 9.3 MiB/s
INFO:  84% (3.0 GiB of 3.5 GiB) in 3m 55s, read: 29.3 MiB/s, write: 24.0 MiB/s
INFO:  86% (3.0 GiB of 3.5 GiB) in 3m 58s, read: 20.0 MiB/s, write: 20.0 MiB/s
INFO:  89% (3.1 GiB of 3.5 GiB) in 4m 1s, read: 34.7 MiB/s, write: 26.7 MiB/s
INFO:  94% (3.3 GiB of 3.5 GiB) in 4m 4s, read: 62.7 MiB/s, write: 46.7 MiB/s
INFO:  99% (3.5 GiB of 3.5 GiB) in 4m 7s, read: 65.3 MiB/s, write: 28.0 MiB/s
INFO: 100% (3.5 GiB of 3.5 GiB) in 4m 10s, read: 1.3 MiB/s, write: 1.3 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 41.92 GiB (93%)
INFO: transferred 3.50 GiB in 255 seconds (14.1 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 106 (00:04:20)
INFO: Backup finished at 2023-01-04 08:04:22
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Starting Backup of VM 109 (qemu)
INFO: Backup started at 2023-01-04 08:04:22
INFO: status = running
INFO: VM Name: HMLRPX02
INFO: include disk 'scsi0' 'LUN2_1:vm-109-disk-1' 20G
ERROR: Backup of VM 109 failed - no such volume 'LUN2_1:vm-109-disk-1'
INFO: Failed at 2023-01-04 08:04:30
INFO: Starting Backup of VM 110 (qemu)
INFO: Backup started at 2023-01-04 08:04:30
INFO: status = running
INFO: VM Name: DoeS-ODOO
INFO: include disk 'scsi0' 'LUN2_1:vm-110-disk-0' 40G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/110/2023-01-04T07:04:30Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '575e7fab-e98c-4b41-826c-d71f3ef8276c'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (228.0 MiB of 40.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 228.0 MiB dirty of 40.0 GiB total
INFO: 100% (228.0 MiB of 228.0 MiB) in 3s, read: 76.0 MiB/s, write: 66.7 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 39.80 GiB (99%)
INFO: transferred 228.00 MiB in 4 seconds (57.0 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 110 (00:00:06)
INFO: Backup finished at 2023-01-04 08:04:36
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Backup job finished with errors
TASK ERROR: job errors

syslog to this time:
Code: 
Jan  4 08:00:02 NucMox03 pvescheduler[760862]: <root@pam> starting task UPID:NucMox03:000B9C1F:00D0ECF6:63B523F2:vzdump::root@pam:
Jan  4 08:00:02 NucMox03 pvescheduler[760863]: INFO: starting new backup job: vzdump 101 102 104 109 105 106 110 --notes-template '{{guestname}}' --quiet 1 --mailto andre.lueneburger@safh
.de --mode snapshot --mailnotification failure --storage PBS01
Jan  4 08:00:02 NucMox03 pvescheduler[760863]: INFO: Starting Backup of VM 106 (qemu)
Jan  4 08:00:40 NucMox03 pvestatd[969]: status update time (9.515 seconds)
Jan  4 08:01:02 NucMox03 pvestatd[969]: status update time (22.365 seconds)
Jan  4 08:01:24 NucMox03 corosync[940]:   [KNET  ] link: host: 3 link: 0 is down
Jan  4 08:01:24 NucMox03 corosync[940]:   [KNET  ] host: host: 3 (passive) best link: 0 (pri: 1)
Jan  4 08:01:24 NucMox03 corosync[940]:   [KNET  ] host: host: 3 has no active links
Jan  4 08:01:26 NucMox03 corosync[940]:   [KNET  ] rx: host: 3 link: 0 is up
Jan  4 08:01:26 NucMox03 corosync[940]:   [KNET  ] link: Resetting MTU for link 0 because host 3 joined
Jan  4 08:01:26 NucMox03 corosync[940]:   [KNET  ] host: host: 3 (passive) best link: 0 (pri: 1)
Jan  4 08:01:26 NucMox03 corosync[940]:   [KNET  ] pmtud: Global data MTU changed to: 8885
Jan  4 08:01:26 NucMox03 pvestatd[969]: status update time (24.114 seconds)
Jan  4 08:02:04 NucMox03 pvestatd[969]: status update time (28.287 seconds)
Jan  4 08:02:42 NucMox03 pvestatd[969]: status update time (17.797 seconds)
Jan  4 08:02:57 NucMox03 corosync[940]:   [KNET  ] link: host: 1 link: 0 is down
Jan  4 08:02:57 NucMox03 corosync[940]:   [KNET  ] host: host: 1 (passive) best link: 0 (pri: 1)
Jan  4 08:02:57 NucMox03 corosync[940]:   [KNET  ] host: host: 1 has no active links
Jan  4 08:02:59 NucMox03 corosync[940]:   [KNET  ] rx: host: 1 link: 0 is up
Jan  4 08:02:59 NucMox03 corosync[940]:   [KNET  ] link: Resetting MTU for link 0 because host 1 joined
Jan  4 08:02:59 NucMox03 corosync[940]:   [KNET  ] host: host: 1 (passive) best link: 0 (pri: 1)
Jan  4 08:02:59 NucMox03 corosync[940]:   [KNET  ] pmtud: Global data MTU changed to: 8885
Jan  4 08:03:25 NucMox03 corosync[940]:   [KNET  ] link: host: 3 link: 0 is down
Jan  4 08:03:25 NucMox03 corosync[940]:   [KNET  ] host: host: 3 (passive) best link: 0 (pri: 1)
Jan  4 08:03:25 NucMox03 corosync[940]:   [KNET  ] host: host: 3 has no active links
Jan  4 08:03:27 NucMox03 corosync[940]:   [KNET  ] rx: host: 3 link: 0 is up
Jan  4 08:03:27 NucMox03 corosync[940]:   [KNET  ] link: Resetting MTU for link 0 because host 3 joined
Jan  4 08:03:27 NucMox03 corosync[940]:   [KNET  ] host: host: 3 (passive) best link: 0 (pri: 1)
Jan  4 08:03:27 NucMox03 corosync[940]:   [KNET  ] pmtud: Global data MTU changed to: 8885
Jan  4 08:03:57 NucMox03 pvestatd[969]: status update time (35.194 seconds)
Jan  4 08:04:22 NucMox03 pvescheduler[760863]: INFO: Finished Backup of VM 106 (00:04:20)
Jan  4 08:04:22 NucMox03 pvescheduler[760863]: INFO: Starting Backup of VM 109 (qemu)
Jan  4 08:04:30 NucMox03 pvescheduler[760863]: ERROR: Backup of VM 109 failed - no such volume 'LUN2_1:vm-109-disk-1'
Jan  4 08:04:30 NucMox03 pvescheduler[760863]: INFO: Starting Backup of VM 110 (qemu)
Jan  4 08:04:36 NucMox03 pvescheduler[760863]: INFO: Finished Backup of VM 110 (00:00:06)
Jan  4 08:04:37 NucMox03 pvescheduler[760863]: INFO: Backup job finished with errors
Jan  4 08:04:37 NucMox03 pvescheduler[760863]: job errors
Jan  4 08:04:37 NucMox03 postfix/pickup[733825]: 3805B12123D: uid=0 from=<PVE-DC@safh.de>
Jan  4 08:04:37 NucMox03 postfix/cleanup[762284]: 3805B12123D: message-id=<20230104070437.3805B12123D@nucmox03.safh.de>
Jan  4 08:04:37 NucMox03 postfix/qmgr[935]: 3805B12123D: from=<PVE-DC@safh.de>, size=21104, nrcpt=1 (queue active)
Jan  4 08:04:37 NucMox03 postfix/smtp[762286]: Untrusted TLS connection established to 10.0.1.3[10.0.1.3]:26: TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange ECDHE
(P-384) server-signature RSA-PSS (4096 bits) server-digest SHA256
Jan  4 08:04:43 NucMox03 postfix/smtp[762286]: 3805B12123D: to=<>, relay=10.0.1.3[10.0.1.3]:26, delay=6.8, delays=0.32/0.01/0.33/6.2, dsn=2.5.0, status=sent (250
2.5.0 OK (41A5963B52505C5EF8))
Jan  4 08:04:43 NucMox03 postfix/qmgr[935]: 3805B12123D: removed


Kind regards,
 
It seems the issue was the following:
Code: 
INFO: include disk 'scsi0' 'LUN2_1:vm-109-disk-1' 20G
ERROR: Backup of VM 109 failed - no such volume 'LUN2_1:vm-109-disk-1'
Does that disk still exist? Or did you delete it without removing it from the config of VM 109?
 
mira said:
It seems the issue was the following:
Code: 
INFO: include disk 'scsi0' 'LUN2_1:vm-109-disk-1' 20G
ERROR: Backup of VM 109 failed - no such volume 'LUN2_1:vm-109-disk-1'
Does that disk still exist? Or did you delete it without removing it from the config of VM 109?
Click to expand...
I just fixed that error, I will lookout if the task still fails.
The VM was recreated after a failure of the filesystem after a hot reboot (system hang).

I will update you later.
 
mira said:
It seems the issue was the following:
Code: 
INFO: include disk 'scsi0' 'LUN2_1:vm-109-disk-1' 20G
ERROR: Backup of VM 109 failed - no such volume 'LUN2_1:vm-109-disk-1'
Does that disk still exist? Or did you delete it without removing it from the config of VM 109?
Click to expand...
So i manually run the task and its not failed anymore.
But the weird text is still inside:

Code: 
INFO: starting new backup job: vzdump 101 102 104 109 105 106 110 100 --notes-template '{{guestname}}' --mailto --mode snapshot --storage PBS01 --mailnotification failure --all 0 --node NucMox03
INFO: Starting Backup of VM 100 (qemu)
INFO: Backup started at 2023-01-04 14:01:46
INFO: status = running
INFO: VM Name: HMLDNS02
INFO: include disk 'scsi0' 'LUN1_1:vm-100-disk-0' 20G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/100/2023-01-04T13:01:46Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task 'da782770-e743-4d58-8ae5-e6043b0fa743'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: created new
INFO:   2% (436.0 MiB of 20.0 GiB) in 3s, read: 145.3 MiB/s, write: 136.0 MiB/s
INFO:   3% (768.0 MiB of 20.0 GiB) in 6s, read: 110.7 MiB/s, write: 110.7 MiB/s
INFO:   5% (1.1 GiB of 20.0 GiB) in 9s, read: 117.3 MiB/s, write: 116.0 MiB/s
INFO:   6% (1.4 GiB of 20.0 GiB) in 12s, read: 101.3 MiB/s, write: 101.3 MiB/s
INFO:   8% (1.7 GiB of 20.0 GiB) in 15s, read: 114.7 MiB/s, write: 114.7 MiB/s
INFO:  10% (2.0 GiB of 20.0 GiB) in 18s, read: 96.0 MiB/s, write: 94.7 MiB/s
INFO:  11% (2.3 GiB of 20.0 GiB) in 21s, read: 116.0 MiB/s, write: 108.0 MiB/s
INFO:  13% (2.7 GiB of 20.0 GiB) in 24s, read: 118.7 MiB/s, write: 118.7 MiB/s
INFO:  14% (2.9 GiB of 20.0 GiB) in 27s, read: 78.7 MiB/s, write: 78.7 MiB/s
INFO:  16% (3.2 GiB of 20.0 GiB) in 30s, read: 106.7 MiB/s, write: 106.7 MiB/s
INFO:  17% (3.6 GiB of 20.0 GiB) in 33s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  19% (3.9 GiB of 20.0 GiB) in 36s, read: 114.7 MiB/s, write: 114.7 MiB/s
INFO:  20% (4.2 GiB of 20.0 GiB) in 39s, read: 81.3 MiB/s, write: 70.7 MiB/s
INFO:  22% (4.5 GiB of 20.0 GiB) in 42s, read: 105.3 MiB/s, write: 101.3 MiB/s
INFO:  23% (4.8 GiB of 20.0 GiB) in 45s, read: 110.7 MiB/s, write: 110.7 MiB/s
INFO:  25% (5.0 GiB of 20.0 GiB) in 48s, read: 78.7 MiB/s, write: 78.7 MiB/s
INFO:  26% (5.4 GiB of 20.0 GiB) in 51s, read: 114.7 MiB/s, write: 114.7 MiB/s
INFO:  28% (5.7 GiB of 20.0 GiB) in 54s, read: 113.3 MiB/s, write: 113.3 MiB/s
INFO:  30% (6.0 GiB of 20.0 GiB) in 57s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  31% (6.4 GiB of 20.0 GiB) in 1m, read: 116.0 MiB/s, write: 105.3 MiB/s
INFO:  33% (6.7 GiB of 20.0 GiB) in 1m 3s, read: 114.7 MiB/s, write: 114.7 MiB/s
INFO:  35% (7.1 GiB of 20.0 GiB) in 1m 6s, read: 118.7 MiB/s, write: 118.7 MiB/s
INFO:  36% (7.4 GiB of 20.0 GiB) in 1m 9s, read: 109.3 MiB/s, write: 109.3 MiB/s
INFO:  38% (7.7 GiB of 20.0 GiB) in 1m 12s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  40% (8.0 GiB of 20.0 GiB) in 1m 15s, read: 104.0 MiB/s, write: 104.0 MiB/s
INFO:  41% (8.3 GiB of 20.0 GiB) in 1m 18s, read: 98.7 MiB/s, write: 89.3 MiB/s
INFO:  43% (8.7 GiB of 20.0 GiB) in 1m 21s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  44% (9.0 GiB of 20.0 GiB) in 1m 24s, read: 110.7 MiB/s, write: 110.7 MiB/s
INFO:  46% (9.3 GiB of 20.0 GiB) in 1m 27s, read: 120.0 MiB/s, write: 120.0 MiB/s
INFO:  48% (9.7 GiB of 20.0 GiB) in 1m 30s, read: 114.7 MiB/s, write: 114.7 MiB/s
INFO:  50% (10.0 GiB of 20.0 GiB) in 1m 33s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  51% (10.3 GiB of 20.0 GiB) in 1m 36s, read: 114.7 MiB/s, write: 94.7 MiB/s
INFO:  53% (10.7 GiB of 20.0 GiB) in 1m 39s, read: 118.7 MiB/s, write: 118.7 MiB/s
INFO:  54% (11.0 GiB of 20.0 GiB) in 1m 42s, read: 92.0 MiB/s, write: 92.0 MiB/s
INFO:  56% (11.2 GiB of 20.0 GiB) in 1m 45s, read: 93.3 MiB/s, write: 93.3 MiB/s
INFO:  57% (11.6 GiB of 20.0 GiB) in 1m 48s, read: 106.7 MiB/s, write: 105.3 MiB/s
INFO:  59% (11.9 GiB of 20.0 GiB) in 1m 51s, read: 116.0 MiB/s, write: 112.0 MiB/s
INFO:  61% (12.2 GiB of 20.0 GiB) in 1m 54s, read: 108.0 MiB/s, write: 84.0 MiB/s
INFO:  62% (12.6 GiB of 20.0 GiB) in 1m 57s, read: 117.3 MiB/s, write: 117.3 MiB/s
INFO:  64% (12.9 GiB of 20.0 GiB) in 2m, read: 109.3 MiB/s, write: 108.0 MiB/s
INFO:  65% (13.2 GiB of 20.0 GiB) in 2m 3s, read: 108.0 MiB/s, write: 108.0 MiB/s
INFO:  67% (13.5 GiB of 20.0 GiB) in 2m 6s, read: 109.3 MiB/s, write: 90.7 MiB/s
INFO:  69% (13.8 GiB of 20.0 GiB) in 2m 9s, read: 110.7 MiB/s, write: 106.7 MiB/s
INFO:  70% (14.1 GiB of 20.0 GiB) in 2m 12s, read: 104.0 MiB/s, write: 90.7 MiB/s
INFO:  71% (14.3 GiB of 20.0 GiB) in 2m 15s, read: 64.0 MiB/s, write: 64.0 MiB/s
INFO:  73% (14.6 GiB of 20.0 GiB) in 2m 18s, read: 94.7 MiB/s, write: 94.7 MiB/s
INFO:  74% (14.9 GiB of 20.0 GiB) in 2m 21s, read: 108.0 MiB/s, write: 108.0 MiB/s
INFO:  76% (15.2 GiB of 20.0 GiB) in 2m 24s, read: 105.3 MiB/s, write: 104.0 MiB/s
INFO:  77% (15.5 GiB of 20.0 GiB) in 2m 27s, read: 109.3 MiB/s, write: 90.7 MiB/s
INFO:  78% (15.7 GiB of 20.0 GiB) in 2m 30s, read: 68.0 MiB/s, write: 68.0 MiB/s
INFO:  79% (16.0 GiB of 20.0 GiB) in 2m 33s, read: 81.3 MiB/s, write: 80.0 MiB/s
INFO:  81% (16.2 GiB of 20.0 GiB) in 2m 36s, read: 82.7 MiB/s, write: 48.0 MiB/s
INFO:  82% (16.5 GiB of 20.0 GiB) in 2m 39s, read: 109.3 MiB/s, write: 4.0 MiB/s
INFO:  84% (16.9 GiB of 20.0 GiB) in 2m 42s, read: 113.3 MiB/s, write: 4.0 MiB/s
INFO:  86% (17.2 GiB of 20.0 GiB) in 2m 45s, read: 110.7 MiB/s, write: 108.0 MiB/s
INFO:  87% (17.5 GiB of 20.0 GiB) in 2m 49s, read: 76.0 MiB/s, write: 68.0 MiB/s
INFO:  89% (17.8 GiB of 20.0 GiB) in 2m 52s, read: 113.3 MiB/s, write: 113.3 MiB/s
INFO:  90% (18.2 GiB of 20.0 GiB) in 2m 55s, read: 117.3 MiB/s, write: 100.0 MiB/s
INFO:  91% (18.4 GiB of 20.0 GiB) in 2m 58s, read: 69.3 MiB/s, write: 69.3 MiB/s
INFO:  93% (18.7 GiB of 20.0 GiB) in 3m 1s, read: 108.0 MiB/s, write: 108.0 MiB/s
INFO:  95% (19.0 GiB of 20.0 GiB) in 3m 4s, read: 108.0 MiB/s, write: 105.3 MiB/s
INFO:  96% (19.3 GiB of 20.0 GiB) in 3m 7s, read: 109.3 MiB/s, write: 28.0 MiB/s
INFO:  98% (19.7 GiB of 20.0 GiB) in 3m 10s, read: 110.7 MiB/s, write: 0 B/s
INFO: 100% (20.0 GiB of 20.0 GiB) in 3m 13s, read: 117.3 MiB/s, write: 13.3 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup is sparse: 2.05 GiB (10%) total zero data
INFO: backup was done incrementally, reused 2.17 GiB (10%)
INFO: transferred 20.00 GiB in 195 seconds (105.0 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 100 (00:03:17)
INFO: Backup finished at 2023-01-04 14:05:03
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Starting Backup of VM 106 (qemu)
INFO: Backup started at 2023-01-04 14:05:03
INFO: status = running
INFO: VM Name: RMD
INFO: include disk 'scsi0' 'LUN2_1:vm-106-disk-1' 45G
INFO: include disk 'efidisk0' 'LUN2_1:vm-106-disk-0' 528K
INFO: include disk 'tpmstate0' 'LUN2_1:vm-106-disk-2' 4M
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/106/2023-01-04T13:05:03Z'
INFO: attaching TPM drive to QEMU for backup
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '6e5d33f6-29b6-42a9-90d9-210dc6c2d8ba'
INFO: resuming VM again
INFO: efidisk0: dirty-bitmap status: OK (drive clean)
INFO: scsi0: dirty-bitmap status: OK (2.4 GiB of 45.0 GiB dirty)
INFO: tpmstate0-backup: dirty-bitmap status: created new
INFO: using fast incremental mode (dirty-bitmap), 2.4 GiB dirty of 45.0 GiB total
INFO:   5% (136.0 MiB of 2.4 GiB) in 3s, read: 45.3 MiB/s, write: 38.7 MiB/s
INFO:  12% (300.0 MiB of 2.4 GiB) in 6s, read: 54.7 MiB/s, write: 53.3 MiB/s
INFO:  14% (368.0 MiB of 2.4 GiB) in 9s, read: 22.7 MiB/s, write: 22.7 MiB/s
INFO:  16% (400.0 MiB of 2.4 GiB) in 12s, read: 10.7 MiB/s, write: 9.3 MiB/s
INFO:  21% (532.0 MiB of 2.4 GiB) in 15s, read: 44.0 MiB/s, write: 42.7 MiB/s
INFO:  27% (680.0 MiB of 2.4 GiB) in 18s, read: 49.3 MiB/s, write: 46.7 MiB/s
INFO:  35% (876.0 MiB of 2.4 GiB) in 21s, read: 65.3 MiB/s, write: 65.3 MiB/s
INFO:  40% (1008.0 MiB of 2.4 GiB) in 24s, read: 44.0 MiB/s, write: 40.0 MiB/s
INFO:  45% (1.1 GiB of 2.4 GiB) in 27s, read: 37.3 MiB/s, write: 36.0 MiB/s
INFO:  49% (1.2 GiB of 2.4 GiB) in 30s, read: 30.7 MiB/s, write: 30.7 MiB/s
INFO:  55% (1.3 GiB of 2.4 GiB) in 33s, read: 48.0 MiB/s, write: 45.3 MiB/s
INFO:  62% (1.5 GiB of 2.4 GiB) in 36s, read: 57.3 MiB/s, write: 56.0 MiB/s
INFO:  69% (1.7 GiB of 2.4 GiB) in 39s, read: 62.7 MiB/s, write: 61.3 MiB/s
INFO:  73% (1.8 GiB of 2.4 GiB) in 42s, read: 28.0 MiB/s, write: 28.0 MiB/s
INFO:  79% (1.9 GiB of 2.4 GiB) in 45s, read: 53.3 MiB/s, write: 48.0 MiB/s
INFO:  82% (2.0 GiB of 2.4 GiB) in 48s, read: 25.3 MiB/s, write: 24.0 MiB/s
INFO:  87% (2.1 GiB of 2.4 GiB) in 51s, read: 42.7 MiB/s, write: 40.0 MiB/s
INFO:  94% (2.3 GiB of 2.4 GiB) in 54s, read: 56.0 MiB/s, write: 52.0 MiB/s
INFO: 100% (2.4 GiB of 2.4 GiB) in 57s, read: 42.7 MiB/s, write: 29.3 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup is sparse: 4.00 MiB (0%) total zero data
INFO: backup was done incrementally, reused 42.75 GiB (94%)
INFO: transferred 2.40 GiB in 76 seconds (32.4 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 106 (00:01:22)
INFO: Backup finished at 2023-01-04 14:06:25
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Starting Backup of VM 109 (qemu)
INFO: Backup started at 2023-01-04 14:06:25
INFO: status = running
INFO: VM Name: HMLRPX02
INFO: include disk 'scsi0' 'LUN2_1:vm-109-disk-1' 20G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/109/2023-01-04T13:06:25Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '84269ca9-019d-4dd1-9f37-79444976cec6'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (176.0 MiB of 20.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 176.0 MiB dirty of 20.0 GiB total
INFO: 100% (176.0 MiB of 176.0 MiB) in 3s, read: 58.7 MiB/s, write: 58.7 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 19.83 GiB (99%)
INFO: transferred 176.00 MiB in 7 seconds (25.1 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 109 (00:00:09)
INFO: Backup finished at 2023-01-04 14:06:34
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Starting Backup of VM 110 (qemu)
INFO: Backup started at 2023-01-04 14:06:34
INFO: status = running
INFO: VM Name: DoeS-ODOO
INFO: include disk 'scsi0' 'LUN2_1:vm-110-disk-0' 40G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/110/2023-01-04T13:06:34Z'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '6247c100-5649-4ca5-8f9c-5506bcf54dac'
INFO: resuming VM again
INFO: scsi0: dirty-bitmap status: OK (332.0 MiB of 40.0 GiB dirty)
INFO: using fast incremental mode (dirty-bitmap), 332.0 MiB dirty of 40.0 GiB total
INFO:  28% (96.0 MiB of 332.0 MiB) in 3s, read: 32.0 MiB/s, write: 32.0 MiB/s
INFO:  80% (268.0 MiB of 332.0 MiB) in 6s, read: 57.3 MiB/s, write: 57.3 MiB/s
INFO: 100% (332.0 MiB of 332.0 MiB) in 9s, read: 21.3 MiB/s, write: 21.3 MiB/s
INFO: Waiting for server to finish backup validation...
INFO: backup was done incrementally, reused 39.68 GiB (99%)
INFO: transferred 332.00 MiB in 13 seconds (25.5 MiB/s)
INFO: adding notes to backup
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Finished Backup of VM 110 (00:00:14)
INFO: Backup finished at 2023-01-04 14:06:48
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Backup job finished successfully
TASK OK
 
Yes, you can ignore that text.
It was introduced during a bug fix and will be removed shortly.
 
  • Like
Reactions: MightySlaytanic and topaLE
sysadminfromhell said:
I just fixed that error, I will lookout if the task still fails.
The VM was recreated after a failure of the filesystem after a hot reboot (system hang).

I will update you later.
Click to expand...
How did you fix this? I restored my system from a previous snaptshot. The config is still there but but the disk isn't (from the host - not the backup). When I try to restore, i get the same error as you
 
I am now experiencing the same issue.

Here is my most recent backup log:

Code: 
INFO: trying to get global lock - waiting...
INFO: got global lock
INFO: starting new backup job: vzdump 105 --mailnotification failure --quiet 1 --node tweety --mailto REDACTED --mode stop --storage pbs-ssd --prune-backups 'keep-daily=3,keep-last=4,keep-monthly=1,keep-weekly=4'
INFO: Starting Backup of VM 105 (lxc)
INFO: Backup started at 2023-01-11 06:01:04
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: CT Name: ct-plex-01
INFO: including mount point rootfs ('/') in backup
INFO: excluding bind mount point mp0 ('/mnt/library') from backup (not a volume)
INFO: excluding bind mount point mp1 ('/mnt/docker') from backup (not a volume)
INFO: stopping virtual guest
INFO: creating Proxmox Backup Server archive 'ct/105/2023-01-11T12:01:04Z'
INFO: run: /usr/bin/proxmox-backup-client backup --crypt-mode=none pct.conf:/var/tmp/vzdumptmp3025782_105/etc/vzdump/pct.conf root.pxar:/mnt/vzsnap0 --include-dev /mnt/vzsnap0/./ --skip-lost-and-found --exclude=/tmp/?* --exclude=/var/tmp/?* --exclude=/var/run/?*.pid --backup-type ct --backup-id 105 --backup-time 1673438464 --repository root@pam@10.10.10.87:ssd_pool
INFO: Starting backup: ct/105/2023-01-11T12:01:04Z
INFO: Client name: tweety
INFO: Starting backup protocol: Wed Jan 11 06:01:05 2023
INFO: storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Downloading previous manifest (Tue Jan 10 06:00:32 2023)
INFO: Upload config file '/var/tmp/vzdumptmp3025782_105/etc/vzdump/pct.conf' to 'root@pam@10.10.10.87:8007:ssd_pool' as pct.conf.blob
INFO: Upload directory '/mnt/vzsnap0' to 'root@pam@10.10.10.87:8007:ssd_pool' as root.pxar.didx
INFO: root.pxar: had to backup 2.458 GiB of 73.251 GiB (compressed 1.839 GiB) in 349.18s
INFO: root.pxar: average backup speed: 7.208 MiB/s
INFO: root.pxar: backup was done incrementally, reused 70.793 GiB (96.6%)
INFO: Uploaded backup catalog (22.287 MiB)
INFO: Duration: 349.29s
INFO: End Time: Wed Jan 11 06:06:55 2023
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: prune older backups with retention: keep-daily=3, keep-last=4, keep-monthly=1, keep-weekly=4
INFO: running 'proxmox-backup-client prune' for 'ct/105'
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: restarting vm
INFO: guest is online again after 352 seconds
INFO: Finished Backup of VM 105 (00:05:52)
INFO: Backup finished at 2023-01-11 06:06:56
storing login ticket failed: $XDG_RUNTIME_DIR must be set
INFO: Backup job finished successfully
TASK OK

I attempted to restore an LXC and it resulted with

Code: 
recovering backed-up configuration from 'pbs-ssd:backup/ct/105/2023-01-11T12:01:04Z'
storing login ticket failed: $XDG_RUNTIME_DIR must be set
restoring 'pbs-ssd:backup/ct/105/2023-01-11T12:01:04Z' now..
storing login ticket failed: $XDG_RUNTIME_DIR must be set
umount: /var/lib/lxc/105/rootfs: target is busy.
command 'umount -d /var/lib/lxc/105/rootfs/' failed: exit code 32
TASK ERROR: unable to restore CT 105 - command '/usr/bin/proxmox-backup-client restore '--crypt-mode=none' ct/105/2023-01-11T12:01:04Z root.pxar /var/lib/lxc/105/rootfs --allow-existing-dirs --repository root@pam@10.10.10.87:ssd_pool' failed: received interrupt

It then destroyed my LXC and it no longer shows up in my VM/CT list.

I've tried creating another LXC with an identical ID and then attempted to restore from backup again. It again resulted in my LXC being destroyed and removed from the list.

Any pointers on how I can restore this LXC? I'd really like to get it back up and running
 
This is a different issue, please open a new thread for it.
 
Also getting this? Runs fine running manually.

Mine backs up the host though maybe just a warning because its running via cron? $XDG_RUNTIME_DIR must be set

/etc/cron.daily/backup-pve-artbackup: Starting backup: host/pve-artbackup/2023-01-16T11:25:01Z Client name: pve-artbackup Starting backup protocol: Mon Jan 16 06:25:01 2023 storing login ticket failed: $XDG_RUNTIME_DIR must be set Downloading previous manifest (Sun Jan 15 17:31:01 2023) Upload directory '/etc' to 'root@pam@10.1.16.44:8007:tank9' as pveartbackup-etc.pxar.didx pveartbackup-etc.pxar: had to backup 2.192 MiB of 2.192 MiB (compressed 575.364 KiB) in 0.19s pveartbackup-etc.pxar: average backup speed: 11.699 MiB/s Uploaded backup catalog (27.844 KiB) Duration: 0.32s End Time: Mon Jan 16 06:25:02 2023
 
Last edited:
It's neither on pve-enterprise nor on pbs-enterprise yet.

I assume you have the `pbs-no-subscription` repository configured on your PBS?

If you want to use it on PVE you'll have to add the `pve-no-subscription` repository. Run `apt update` followed by `apt install proxmox-backup-client`.
Afterwards you can disable the `pve-no-subscription` repository again.
 
  • Like
Reactions: entilza
I'm still seeing the same issue with proxmox-backup-client 2.3.3 launched from a vzdump hook skript.

...
Code: 
INFO: client version: 2.3.3
INFO: server version: 2.2.5
INFO: Starting backup: host/pve/2023-03-05T12:01:24Z
INFO: Client name: pve
INFO: Starting backup protocol: Sun Mar  5 13:01:24 2023
INFO: No previous manifest available.
INFO: Upload directory '/' to 'admin@pbs@192.x.y.z:8007' as root.pxar.didx
INFO: root.pxar: had to backup 48.057 MiB of 48.057 MiB (compressed 43.989 MiB) in 0.60s
INFO: root.pxar: average backup speed: 80.089 MiB/s
INFO: Uploaded backup catalog (13.545 KiB)
INFO: Duration: 0.71s
INFO: End Time: Sun Mar  5 13:01:25 2023
INFO: Error: $XDG_RUNTIME_DIR must be set
ERROR: Backup of VM 100 failed - command '/root/vzdump-hook-script.sh backup-end snapshot 100' failed: exit code 255
INFO: Failed at 2023-03-05 13:01:25
....

This causes pve to indicate the backup job failed, although it actually completed successfully.
 
carl said:
I'm still seeing the same issue with proxmox-backup-client 2.3.3 launched from a vzdump hook skript.

...
Code: 
INFO: client version: 2.3.3
INFO: server version: 2.2.5
INFO: Starting backup: host/pve/2023-03-05T12:01:24Z
INFO: Client name: pve
INFO: Starting backup protocol: Sun Mar  5 13:01:24 2023
INFO: No previous manifest available.
INFO: Upload directory '/' to 'admin@pbs@192.x.y.z:8007' as root.pxar.didx
INFO: root.pxar: had to backup 48.057 MiB of 48.057 MiB (compressed 43.989 MiB) in 0.60s
INFO: root.pxar: average backup speed: 80.089 MiB/s
INFO: Uploaded backup catalog (13.545 KiB)
INFO: Duration: 0.71s
INFO: End Time: Sun Mar  5 13:01:25 2023
INFO: Error: $XDG_RUNTIME_DIR must be set
ERROR: Backup of VM 100 failed - command '/root/vzdump-hook-script.sh backup-end snapshot 100' failed: exit code 255
INFO: Failed at 2023-03-05 13:01:25
....

This causes pve to indicate the backup job failed, although it actually completed successfully.
Click to expand...
No, the issue in your case is the line starting with ERROR.
ERROR: Backup of VM 100 failed - command '/root/vzdump-hook-script.sh backup-end snapshot 100' failed: exit code 255
Click to expand...
Your hook script seems to be faulty.
 
Mira, well, for what it's worth: These are the last two lines in the hook script in question:

Code: 
...
proxmox-backup-client backup root.pxar:/ --all-file-systems --backup-type host
proxmox-backup-client logout

I doubt that the hook script is faulty. But, rather, that the proxmox-backup-client logout is causing the problem
 
You must log in or register to reply here.

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!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

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!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back