unable to read dynamic index

B

boomam

Member
Jan 5, 2023
60
10
13
Hi,
One of my Proxmox Backup Client systems has recently started generating errors when backing up - along the lines of -
Error downloading .didx from previous manifest: unable to read dynmamic index 'data00.pxar.didx' - Invalid argument (os error 22)

I know for a fact that the syntax is correct as the same syntax i use (detail below) i use on my other PBS Client systems too.

Bash: 
# env variables
export PBS_REPOSITORY="user@pbs!token-name@backup-server.com:datastore"
export PBS_PASSWORD="123456789"

# Backup
proxmox-backup-client backup --skip-lost-and-found true data00.pxar:/data/

If i do a `journalctl -f` during a test backup, on PBS, i see nothing out of the ordinary either -
Code: 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: starting new backup on datastore 'datastore' from ::ffff:1.2.3.4: "host/client-01/2024-04-08T15:42:10Z"                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: protocol upgrade done                                                                                                         
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: GET /previous_backup_time                                                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: GET /previous                                                                                                                 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: download 'index.json.blob' from previous backup.                                                                               
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: GET /previous                                                                                                                 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_index                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: register chunks in 'client-01-data-00.pxar.didx' from previous backup.                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: created new dynamic index 1 ("host/client-01/2024-04-08T15:42:10Z/catalog.pcat1.didx")                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: download 'client-01-data-00.pxar.didx' from previous backup.                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_index                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: created new dynamic index 2 ("host/client-01/2024-04-08T15:42:10Z/client-01-data-00.pxar.didx")                                   
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_chunk                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: upload_chunk done: 3694 bytes, d79f0fa0f9351b3098aa344263a403bce551971277817571644ac4b88ff3cc9a                               
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: PUT /dynamic_index                                                                                                             
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: dynamic_append 1 chunks                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: successfully added chunk d79f0fa0f9351b3098aa344263a403bce551971277817571644ac4b88ff3cc9a to dynamic index 2 (offset 0, size 36
94)                                                                                                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_close                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Upload statistics for 'client-01-data-00.pxar.didx'                                                                             
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: UUID: 123abc                                                                                         
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Checksum: 456xyz                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Size: 3694                                                                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Chunk count: 1                                                                                                                 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Upload size: 3694 (100%)                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Compression: 30%                                                                                                               
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: successfully closed dynamic index 2                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_chunk                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: upload_chunk done: 127 bytes, 99d415c795f1194274d8429c71db12049be8263b12463d484bfcaac0e1d66f12                                 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: PUT /dynamic_index                                                                                                             
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: dynamic_append 1 chunks                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: successfully added chunk 99d415c795f1194274d8429c71db12049be8263b12463d484bfcaac0e1d66f12 to dynamic index 1 (offset 0, size 12
7)                                                                                                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /dynamic_close                                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Upload statistics for 'catalog.pcat1.didx'                                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: UUID: 123abc                                                                                         
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Checksum: 456xyz                                                   
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Size: 127                                                                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Chunk count: 1                                                                                                                 
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Upload size: 127 (100%)                                                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Duplicates: 0+1 (100%)                                                                                                         
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: Compression: 108%                                                                                                             
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: successfully closed dynamic index 1                                                                                           
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /blob                                                                                                                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: add blob "/mnt/datastore/datastore/host/client-01/2024-04-08T15:42:10Z/index.json.blob" (322 bytes, comp: 322)                     
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: POST /finish                                                                                                                   
Apr 08 11:42:10 backup-01 proxmox-backup-[845]: backup-01 proxmox-backup-proxy[845]: syncing filesystem                                                                       
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: successfully finished backup                                                                                                   
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: backup finished successfully                                                                                                   
Apr 08 11:42:10 backup-01 proxmox-backup-proxy[845]: TASK OK


Equally, I dont see anything in syslog or elseware that would point to an issue, but to start with, what is error 22?
Right now, I'm thinking its maybe a red-herring and a client side error, but it does appear to be stopping backups from completing (the above script is ran on a cron schedule).

Anyone got any ideas?

Thanks!
 
Hi!
hmm, this is interesting... I think it's the mmap syscall (which is used to map the previous dynamic index into memory) fails. Does every invocation of the client return this error or only sometimes?
Try executing a verify job on the server to see if there are some broken backups as well.
 
ggoller said:
Hi!
hmm, this is interesting... I think it's the mmap syscall (which is used to map the previous dynamic index into memory) fails. Does every invocation of the client return this error or only sometimes?
Try executing a verify job on the server to see if there are some broken backups as well.
Click to expand...
Hi,
Every time unfortunatelly.

Verifications appear to work fine, too.
I'm also 99% sure its not a network issue, as i have other clients on the same LAN segment, routing the same way to the PBS, that does not have the issue.
 
Hi,

This issue seems still be occurring and I thought to try and dig into it some more. I fess up right away that the 3 clients I have running are on ARM64 processors using the externally created ARM installer. I recognize that this is an unsupported configuration and thus might contribute to my issue. However I would like to try and determine if a fix can be made.

With that said, the original speculation that this is in the mmap sys call appears to be true. I believe this is due to running on hardware where the default page size is 16Kb. To confirm this I switched to the 4Kb kernel. However this does impose a performance penalty (approx. 7%) and thus it's not optimal.

The strace output with the issues is as follows:
Code: 
lseek(11, 0, SEEK_SET)                  = 0
newfstatat(11, "", {st_mode=S_IFREG|0644, st_size=4136, ...}, AT_EMPTY_PATH) = 0
read(11, "\34\221N\245\31\272\263\315g\239\317L\352B\252\234/\373\314\367\337\235#\341\25\32h\0\0\0\0"..., 4096) = 4096
mmap(NULL, 40, PROT_READ, MAP_PRIVATE, 11, 0x1000) = -1 EINVAL (Invalid argument)
close(11)                               = 0
write(2, "Error downloading .didx from pre"..., 128Error downloading .didx from previous manifest: unable to read dynamic index 'home.mpxar.didx' - Invalid argument (os error 22)
) = 128

Running with the 4kb kernel solves the issue and everything is back to expected behavior (minus lower overall performance) .

While proxmox-backup-client does work even with the lack of dindex support, the backup times are hugely different. In my configuration - a backup that fails to download the dynamic index takes approximately 24 minutes to run, with a valid dynamic index it takes approximately 5 seconds to run - quite a huge difference.

Thanks,
-Jeff
 
thanks for the interesting data point.. @boomam are you also on arm64 or some other custom build?
 
Hi @fabian ,
The original issue went away, but both systems were x86.
I have however started seeing the error again as of this morning, this time with PVE being able to backup to PBS (a VM on Unraid).
Exact same errors, both PVE & PBS running the latest versions.

Interestingly, i have a remote PBS running the latest version too, but is bare metal. That particular PBS works fine as a backup target.
 
To add to this, i 'fixed' it for myself by flipping the protocol over to NFS and wiping the storage.
I didn't have time to mess around too much.
 
You must log in or register to reply here.
Top Bottom