"Error: ENOENT: No such file or directory" in post backup mail

Klug · Jan 26, 2021

Hi.

I got this in my mailbox this morning, last night backup; if the mail is right, one of the VM did not backup correctly.

Code:

137: 2021-01-26 01:03:23 INFO: Starting Backup of VM 137 (qemu)
137: 2021-01-26 01:03:23 INFO: status = running
137: 2021-01-26 01:03:23 INFO: VM Name: lm-old
137: 2021-01-26 01:03:23 INFO: include disk 'scsi0' 'SSD:vm-137-disk-0' 32G
137: 2021-01-26 01:03:23 INFO: backup mode: snapshot
137: 2021-01-26 01:03:23 INFO: ionice priority: 7
137: 2021-01-26 01:03:23 INFO: creating Proxmox Backup Server archive 'vm/137/2021-01-26T00:03:23Z'
137: 2021-01-26 01:03:26 INFO: skipping guest-agent 'fs-freeze', agent configured but not running?
137: 2021-01-26 01:03:26 INFO: enabling encryption
137: 2021-01-26 01:03:27 INFO: started backup task '0226a74e-8cc1-4602-b597-141fbdffcbf2'
137: 2021-01-26 01:03:27 INFO: resuming VM again
137: 2021-01-26 01:03:27 INFO: scsi0: dirty-bitmap status: OK (1.6 GiB of 32.0 GiB dirty)
137: 2021-01-26 01:03:27 INFO: using fast incremental mode (dirty-bitmap), 1.6 GiB dirty of 32.0 GiB total
137: 2021-01-26 01:03:30 INFO:   9% (160.0 MiB of 1.6 GiB) in  3s, read: 53.3 MiB/s, write: 50.7 MiB/s
137: 2021-01-26 01:03:33 INFO:  19% (332.0 MiB of 1.6 GiB) in  6s, read: 57.3 MiB/s, write: 57.3 MiB/s
137: 2021-01-26 01:03:36 INFO:  29% (492.0 MiB of 1.6 GiB) in  9s, read: 53.3 MiB/s, write: 53.3 MiB/s
137: 2021-01-26 01:03:39 INFO:  40% (676.0 MiB of 1.6 GiB) in 12s, read: 61.3 MiB/s, write: 49.3 MiB/s
137: 2021-01-26 01:03:42 INFO:  44% (752.0 MiB of 1.6 GiB) in 15s, read: 25.3 MiB/s, write: 10.7 MiB/s
137: 2021-01-26 01:03:45 INFO:  56% (948.0 MiB of 1.6 GiB) in 18s, read: 65.3 MiB/s, write: 36.0 MiB/s
137: 2021-01-26 01:03:48 INFO:  67% (1.1 GiB of 1.6 GiB) in 21s, read: 61.3 MiB/s, write: 61.3 MiB/s
137: 2021-01-26 01:03:51 INFO:  73% (1.2 GiB of 1.6 GiB) in 24s, read: 37.3 MiB/s, write: 37.3 MiB/s
137: 2021-01-26 01:03:54 INFO:  80% (1.3 GiB of 1.6 GiB) in 27s, read: 37.3 MiB/s, write: 37.3 MiB/s
137: 2021-01-26 01:03:57 INFO:  81% (1.3 GiB of 1.6 GiB) in 30s, read: 4.0 MiB/s, write: 4.0 MiB/s
137: 2021-01-26 01:04:00 INFO:  86% (1.4 GiB of 1.6 GiB) in 33s, read: 30.7 MiB/s, write: 30.7 MiB/s
137: 2021-01-26 01:04:03 INFO:  94% (1.6 GiB of 1.6 GiB) in 36s, read: 44.0 MiB/s, write: 44.0 MiB/s
137: 2021-01-26 01:04:06 INFO: 100% (1.6 GiB of 1.6 GiB) in 39s, read: 32.0 MiB/s, write: 30.7 MiB/s
137: 2021-01-26 01:04:19 INFO: backup was done incrementally, reused 30.53 GiB (95%)
137: 2021-01-26 01:04:19 INFO: transferred 1.65 GiB in 52 seconds (32.5 MiB/s)
137: 2021-01-26 01:04:21 ERROR: Backup of VM 137 failed - proxmox-backup-client failed: Error: ENOENT: No such file or directory

Looking at the PBS web interface, this backup is successful:

It looks like backup happened but not prune (not prune line in /var/log/proxmox-backup/tasks/archive either).

Where can I look elswhere to have more information?

dcsapak · Jan 26, 2021

anything in the syslog of either machine (client/server)?

Klug · Jan 26, 2021

There's a 400 error (bad request) in PBS'syslog:

Code:

Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Upload statistics for 'drive-scsi0.img.fidx'
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: UUID: 517ba5ee62f74948b3f5f12cde84d5b5
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Checksum: 51dd8771be157549e3ce3ddcceeb43b149c60e1e385e616a7cbe83279b4c04b1
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Size: 1769996288
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Chunk count: 422
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Upload size: 1585446912 (89%)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Duplicates: 44+2 (10%)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Compression: 44%
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: successfully closed fixed index 1
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/137/2021-01-26T00:03:23Z/index.json.blob" (437 bytes, comp: 437)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: successfully finished backup
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: backup finished successfully
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: TASK OK
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117C:600F5C4F:backup:BKP_PBS_NCP\x3avm-137:root@pam:'
Jan 26 01:04:19 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: retention options: --keep-last 60
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Starting prune on store "BKP_PBS_NCP" group "vm/131"
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-27T00:01:54Z remove
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: removing backup snapshot "/mnt/BKP/vm/131/2020-11-27T00:01:54Z"
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-28T00:02:18Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-29T00:02:07Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-30T00:02:28Z keep
.../...
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-24T00:02:08Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-25T00:04:52Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-26T00:03:41Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: TASK OK
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117F:600F5C85:prune:BKP_PBS_NCP\x3avm-131:root@pam:'
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: GET /api2/json/admin/datastore/BKP_PBS_NCP/snapshots?: 400 Bad Request: [client [::ffff:192.168.88.153]:52288] ENOENT: No such file or directory
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Upload backup log to BKP_PBS_NCP/vm/131/2021-01-26T00:03:41Z/client.log.blob

If I grep PBS' syslog for the VM ID, I get this:

Code:

Jan 26 01:03:27 pbs proxmox-backup-proxy[6187]: starting new backup on datastore 'BKP_PBS_NCP': "vm/137/2021-01-26T00:03:23Z"
Jan 26 01:03:27 pbs proxmox-backup-proxy[6187]: created new fixed index 1 ("vm/137/2021-01-26T00:03:23Z/drive-scsi0.img.fidx")
Jan 26 01:03:27 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/137/2021-01-26T00:03:23Z/qemu-server.conf.blob" (387 bytes, comp: 387)
Jan 26 01:03:39 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/137/2021-01-26T00:03:23Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/137/2021-01-26T00:03:23Z/index.json.blob" (437 bytes, comp: 437)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117C:600F5C4F:backup:BKP_PBS_NCP\x3avm-137:root@pam:'
Jan 26 02:30:02 pbs proxmox-backup-proxy[6187]: removing backup snapshot "/mnt/BKP/vm/137/2020-11-27T00:01:35Z"

In the host syslog, grepping the job:

Code:

Jan 26 01:00:03 pve03 vzdump[3153251]: INFO: starting new backup job: vzdump --pool Clients --storage PBS_NCP --mailto support@domain.tld --quiet 1 --mailnotification failure --mode snapshot
Jan 26 01:00:03 pve03 vzdump[3153251]: INFO: Starting Backup of VM 122 (qemu)
Jan 26 01:03:23 pve03 vzdump[3153251]: INFO: Finished Backup of VM 122 (00:03:20)
Jan 26 01:03:23 pve03 vzdump[3153251]: INFO: Starting Backup of VM 137 (qemu)
Jan 26 01:03:26 pve03 vzdump[3153251]: VM 137 qmp command failed - VM 137 qmp command 'guest-ping' failed - got timeout
Jan 26 01:04:21 pve03 vzdump[3153251]: ERROR: Backup of VM 137 failed - proxmox-backup-client failed: Error: ENOENT: No such file or directory
Jan 26 01:04:21 pve03 vzdump[3153251]: INFO: Backup job finished with errors
Jan 26 01:04:21 pve03 vzdump[3153251]: job errors

dcsapak · Jan 26, 2021

ok so it seems that there is a directory /mnt/BKP/vm/148/2021-01-26T00:00:03Z/ that does not have an index.json.blob
is that right? why could that be?

Klug · Jan 26, 2021

There is this error for several VM.

Code:

Jan 26 00:30:11 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/168/2021-01-25T23:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 00:30:13 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/140/2021-01-25T23:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 00:31:16 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/168/2021-01-25T23:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 00:31:18 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/140/2021-01-25T23:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 00:34:08 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/168/2021-01-25T23:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 00:34:50 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/154/2021-01-25T23:34:10Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:00:41 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:00:43 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/122/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:00:44 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/171/2021-01-26T00:00:02Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:00:46 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/123/2021-01-26T00:00:02Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:01:26 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:01:28 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/122/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:01:30 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/123/2021-01-26T00:00:02Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:03:17 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:03:18 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:03:18 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:03:36 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:03:39 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/137/2021-01-26T00:03:23Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:13 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:19 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:30:40 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/126/2021-01-26T00:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:30:46 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/105/2021-01-26T00:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:30:47 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/105/2021-01-26T00:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:38:29 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/105/2021-01-26T00:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 04:30:11 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/169/2021-01-26T03:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 04:32:26 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/169/2021-01-26T03:30:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:00:17 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/133/2021-01-26T04:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:00:21 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/134/2021-01-26T04:00:20Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:00:33 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/135/2021-01-26T04:00:23Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:01:01 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/136/2021-01-26T04:00:41Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:01:12 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/159/2021-01-26T04:01:04Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:01:17 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/141/2021-01-26T04:01:13Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 05:01:31 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/141/2021-01-26T04:01:13Z/index.json.blob"' - No such file or directory (os error 2)'

None of them is the one with the "failed backup" error.
No idea why the error happens (while for these VM the backup seems to happen correctly).

For each of these files, it seems to be created right after the error, example for the last line:

Code:

# ls -l /mnt/BKP/vm/141/2021-01-26T04:01:13Z/index.json.blob
-rw-r--r-- 1 backup backup 512 Jan 26 05:02 /mnt/BKP/vm/141/2021-01-26T04:01:13Z/index.json.blob

dcsapak · Jan 26, 2021

ah ok after looking at the errors again and at the source, that line is a red herring (its a warning only)

the real error is:

Klug said:
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: GET /api2/json/admin/datastore/BKP_PBS_NCP/snapshots?: 400 Bad Request: [client [::ffff:192.168.88.153]:52288] ENOENT: No such file or directory

it seems the snapshots api call hand some kind of error

can you check the pbs syslog what happened around this time? e.g. from 01:04:00 to 01:05:00 ?

Klug · Jan 26, 2021

Most of it is is post #3.

Longer version below:

Code:

Jan 26 01:03:41 pbs proxmox-backup-proxy[6187]: starting new backup on datastore 'BKP_PBS_NCP': "vm/131/2021-01-26T00:03:41Z"
Jan 26 01:03:41 pbs proxmox-backup-proxy[6187]: download 'index.json.blob' from previous backup.
Jan 26 01:03:41 pbs proxmox-backup-proxy[6187]: register chunks in 'drive-scsi0.img.fidx' from previous backup.
Jan 26 01:03:42 pbs proxmox-backup-proxy[6187]: download 'drive-scsi0.img.fidx' from previous backup.
Jan 26 01:03:42 pbs proxmox-backup-proxy[6187]: created new fixed index 1 ("vm/131/2021-01-26T00:03:41Z/drive-scsi0.img.fidx")
Jan 26 01:03:47 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/131/2021-01-26T00:03:41Z/qemu-server.conf.blob" (335 bytes, comp: 335)
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Upload statistics for 'drive-scsi0.img.fidx'
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: UUID: a685a4360edd46af9bbbcbbfb0f6c927
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Checksum: 5457d4f9f7587f0f04351721055beac5a674dd41ed0c71ac2df471303b877070
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Size: 847249408
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Chunk count: 202
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Upload size: 637534208 (75%)
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Duplicates: 50+4 (26%)
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Compression: 5%
Jan 26 01:04:12 pbs systemd[1]: Starting Daily Proxmox Backup Server update and maintenance activities...
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: successfully closed fixed index 1
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/131/2021-01-26T00:03:41Z/index.json.blob" (438 bytes, comp: 438)
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: successfully finished backup
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: backup finished successfully
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: TASK OK
Jan 26 01:04:12 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117E:600F5C5D:backup:BKP_PBS_NCP\x3avm-131:root@pam:'
Jan 26 01:04:12 pbs proxmox-daily-update[7949]: starting apt-get update
Jan 26 01:04:13 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Hit:1 http://ftp.fr.debian.org/debian buster InRelease
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Get:2 http://ftp.fr.debian.org/debian buster-updates InRelease [51.9 kB]
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Get:3 http://security.debian.org buster/updates InRelease [65.4 kB]
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Hit:4 http://repository.veeam.com/backup/linux/agent/dpkg/debian/public stable InRelease
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Hit:5 http://download.proxmox.com/debian/pbs buster InRelease
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Get:6 http://security.debian.org buster/updates/main amd64 Packages [270 kB]
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Fetched 387 kB in 2s (198 kB/s)
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Reading package lists...
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: TASK OK
Jan 26 01:04:17 pbs proxmox-daily-update[7949]: Detected stopped task 'UPID:pbs:00001F0D:18EE8530:00000000:600F5C7C:aptupdate::root@pam:'
Jan 26 01:04:17 pbs systemd[1]: proxmox-backup-daily-update.service: Succeeded.
Jan 26 01:04:17 pbs systemd[1]: Started Daily Proxmox Backup Server update and maintenance activities.
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Upload statistics for 'drive-scsi0.img.fidx'
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: UUID: 517ba5ee62f74948b3f5f12cde84d5b5
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Checksum: 51dd8771be157549e3ce3ddcceeb43b149c60e1e385e616a7cbe83279b4c04b1
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Size: 1769996288
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Chunk count: 422
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Upload size: 1585446912 (89%)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Duplicates: 44+2 (10%)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Compression: 44%
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: successfully closed fixed index 1
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: add blob "/mnt/BKP/vm/137/2021-01-26T00:03:23Z/index.json.blob" (437 bytes, comp: 437)
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: successfully finished backup
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: backup finished successfully
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: TASK OK
Jan 26 01:04:18 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117C:600F5C4F:backup:BKP_PBS_NCP\x3avm-137:root@pam:'
Jan 26 01:04:19 pbs proxmox-backup-proxy[6187]: error during snapshot file listing: 'unable to load blob '"/mnt/BKP/vm/148/2021-01-26T00:00:03Z/index.json.blob"' - No such file or directory (os error 2)'
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: retention options: --keep-last 60
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Starting prune on store "BKP_PBS_NCP" group "vm/131"
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-27T00:01:54Z remove
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: removing backup snapshot "/mnt/BKP/vm/131/2020-11-27T00:01:54Z"
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-28T00:02:18Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-29T00:02:07Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-11-30T00:02:28Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-01T00:03:01Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-02T00:01:43Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-03T00:01:52Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-04T00:01:36Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-05T00:01:50Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-06T00:01:59Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-07T00:01:59Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-08T00:02:05Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-09T00:01:46Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-10T00:02:57Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-11T00:02:32Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-12T00:02:01Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-13T00:02:45Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-14T00:06:18Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-15T00:03:53Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-16T00:02:40Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-17T00:01:51Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-18T00:01:53Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-19T00:02:18Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-20T00:02:13Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-21T00:03:14Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-22T00:02:08Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-23T00:05:18Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-24T00:04:55Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-25T00:02:07Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-26T00:01:28Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-27T00:01:31Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-28T00:01:40Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-29T00:01:58Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-30T00:02:19Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2020-12-31T00:01:45Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-01T00:01:46Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-02T00:01:33Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-03T00:01:36Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-04T00:02:26Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-05T00:01:38Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-06T00:01:22Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-07T00:01:45Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-08T00:02:19Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-09T00:02:02Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-10T00:04:25Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-11T00:01:59Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-12T00:01:54Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-13T00:02:17Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-14T00:02:23Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-15T00:02:10Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-16T00:02:38Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-17T00:06:12Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-18T00:05:43Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-19T00:05:52Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-20T00:02:13Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-21T00:02:31Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-22T00:02:29Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-23T00:02:05Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-24T00:02:08Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-25T00:04:52Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: vm/131/2021-01-26T00:03:41Z keep
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: TASK OK
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Detected stopped task 'UPID:pbs:0000182B:063F1EF8:0000117F:600F5C85:prune:BKP_PBS_NCP\x3avm-131:root@pam:'
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: GET /api2/json/admin/datastore/BKP_PBS_NCP/snapshots?: 400 Bad Request: [client [::ffff:192.168.88.153]:52288] ENOENT: No such file or directory
Jan 26 01:04:21 pbs proxmox-backup-proxy[6187]: Upload backup log to BKP_PBS_NCP/vm/131/2021-01-26T00:03:41Z/client.log.blob

Log jumps to 01:10:07 after that.

dcsapak · Jan 27, 2021

mhmmm.. does not say that much

could you please post the version of your pbs?

proxmox-backup-manager versions --verbose

?

Klug · Jan 27, 2021

Hi.

The error did not happen this night.

Code:

root@pbs:~# proxmox-backup-manager versions --verbose
proxmox-backup             1.0-4        running kernel: 5.4.78-2-pve
proxmox-backup-server      1.0.6-1      running version: 1.0.6
pve-kernel-5.4             6.3-3
pve-kernel-helper          6.3-3
pve-kernel-5.4.78-2-pve    5.4.78-2
pve-kernel-5.4.65-1-pve    5.4.65-1
ifupdown2                  3.0.0-1+pve3
libjs-extjs                6.0.1-10
proxmox-backup-docs        1.0.6-1
proxmox-backup-client      1.0.6-1
proxmox-mini-journalreader 1.1-1
proxmox-widget-toolkit     2.4-3
pve-xtermjs                4.7.0-3
smartmontools              7.1-pve2
zfsutils-linux             0.8.5-pve1

dcsapak · Jan 27, 2021

Klug said:
The error did not happen this night.

yeah my guess is that we do not handle vanishing backups correctly when listing them

so trying to get a list of snapshots while a prune is running could fail
i'll see if i can reproduce/fix it

Klug · Jan 27, 2021

It might be related to the slowness of my repo (FreeNAS NFS mount) and might not happen with a dedicated server + local ZFS.

Search

Search

"Error: ENOENT: No such file or directory" in post backup mail

Klug

Well-Known Member

dcsapak

Proxmox Staff Member

Klug

Well-Known Member

dcsapak

Proxmox Staff Member

Klug

Well-Known Member

dcsapak

Proxmox Staff Member

Klug

Well-Known Member

dcsapak

Proxmox Staff Member

Klug

Well-Known Member

dcsapak

Proxmox Staff Member

Klug

Well-Known Member