Closed Finn0811 closed 6 months ago
wofferl
commented
11 months ago Maybe some kind of file system problem. Which filesystem you are using where /opt/fwpbs02 is located? Was there already existing backups from an older installation in /opt/fwpbs02 or was it initialized with version 3.0.4?
Finn0811
commented
11 months ago Filesystem is ext4, it's the internal SD card to try before using an additional SSD.
root@raspberrypi:~# cat /etc/fstab
proc /proc proc defaults 0 0
PARTUUID=b2a89280-01 /boot/firmware vfat defaults 0 2
PARTUUID=b2a89280-02 / ext4 defaults,noatime 0 1
# a swapfile is not a swap partition, no line here
# use dphys-swapfile swap[on|off] for thatNo there were no existing backups, it was newly initialized with 3.0.4.
wofferl
commented
11 months ago What version is your pve server? Can you show if any files are written to the ns folder? ls -lR /opt/fwpbs02/ns
Does host or ct backups work?
Finn0811
commented
11 months ago My pve server is 8.0.4.
root@raspberrypi:~# ls -lR /opt/fwpbs02/ns/
/opt/fwpbs02/ns/:
total 12
drwxr-xr-x 2 backup backup 4096 Nov 19 13:16 ffpve01
drwxr-xr-x 4 backup backup 4096 Nov 20 16:43 fwpve01
drwxr-xr-x 2 backup backup 4096 Nov 19 13:15 fwpve02
/opt/fwpbs02/ns/ffpve01:
total 0
/opt/fwpbs02/ns/fwpve01:
total 8
drwxr-xr-x 3 backup backup 4096 Nov 20 16:43 host
drwxr-xr-x 3 backup backup 4096 Nov 19 20:37 vm
/opt/fwpbs02/ns/fwpve01/host:
total 4
drwxr-xr-x 3 backup backup 4096 Nov 20 16:49 fwpve01
/opt/fwpbs02/ns/fwpve01/host/fwpve01:
total 8
drwxr-xr-x 2 backup backup 4096 Nov 20 16:49 2023-11-20T15:49:53Z
-rw-r--r-- 1 backup backup 9 Nov 20 16:43 owner
'/opt/fwpbs02/ns/fwpve01/host/fwpve01/2023-11-20T15:49:53Z':
total 20
-rw-r--r-- 1 backup backup 4136 Nov 20 16:49 catalog.pcat1.didx
-rw-r--r-- 1 backup backup 4136 Nov 20 16:49 etc.pxar.didx
-rw-r--r-- 1 backup backup 386 Nov 20 16:49 index.json.blob
/opt/fwpbs02/ns/fwpve01/vm:
total 4
drwxr-xr-x 2 backup backup 4096 Nov 20 16:26 101
/opt/fwpbs02/ns/fwpve01/vm/101:
total 4
-rw-r--r-- 1 backup backup 9 Nov 19 20:37 owner
/opt/fwpbs02/ns/fwpve02:
total 0Host backups do work, yes. I currently don't have any container to test with.
wofferl
commented
11 months ago This will not be easy to debug and I don't think that is a problem from this proxmox backup build. Is there anything besides the shown log above in the syslog or in the log on the pve node that points to a problem?
You can install auditd and create a rule for debugging:
auditctl -w /opt/fwpbs02/ -p rwa -k proxmox
This will log all file accesses in your datastore directory to /var/log/audit/audit.log.
You can than search for unsuccessful operations:
ausearch -k proxmox -sv no
This should show the failed operations to debug this further.
Finn0811
commented
11 months ago The syslog shows nothing more than the output from proxmox backup server.
The auditlog doesn't even show one file access in that directory at the time I try to create a backup.
Trying with "touch /opt/fwpbs02/ns/fwpve01/vm/101/test" does log file access so it seems to work. Looks like proxmox backup server doesn't even want to try to write into it. :(
wofferl
commented
11 months ago That is strange. There are normally several filesystem operations between GET /previous and POST /fixed_index, so there should be entries in audit.log if the watch rule above is set.
From the error EINVAL: Invalid argument your filesystem in /opt/fwpbs02 seems to missing features the proxmox backup uses.
Are you using xattr or acl on your filesystem?
Maybe you can post the output of tune2fs -l /dev/disk/by-partuuid/b2a89280-02 and mount.
Finn0811
commented
11 months ago I think xattr and acl is enabeld by default, at least I didn't modify anything like that.
root@raspberrypi:~# tune2fs -l /dev/disk/by-partuuid/b2a89280-02
tune2fs 1.47.0 (5-Feb-2023)
Filesystem volume name: rootfs
Last mounted on: /
Filesystem UUID: cb6f0e18-5add-4177-ab98-e9f0235e06b3
Filesystem magic number: 0xEF53
Filesystem revision #: 1 (dynamic)
Filesystem features: has_journal ext_attr resize_inode dir_index filetype needs_recovery extent flex_bg sparse_super large_file dir_nlink extra_isize metadata_csum
Filesystem flags: unsigned_directory_hash
Default mount options: user_xattr acl
Filesystem state: clean
Errors behavior: Continue
Filesystem OS type: Linux
Inode count: 7622368
Block count: 31085056
Reserved block count: 1554233
Free blocks: 27281458
Free inodes: 7352488
First block: 0
Block size: 4096
Fragment size: 4096
Reserved GDT blocks: 306
Blocks per group: 32768
Fragments per group: 32768
Inodes per group: 8032
Inode blocks per group: 502
Flex block group size: 16
Filesystem created: Tue Oct 10 06:04:14 2023
Last mount time: Mon Nov 20 20:02:50 2023
Last write time: Mon Nov 20 20:02:48 2023
Mount count: 12
Maximum mount count: -1
Last checked: Tue Oct 10 06:04:14 2023
Check interval: 0 (<none>)
Lifetime writes: 21 GB
Reserved blocks uid: 0 (user root)
Reserved blocks gid: 0 (group root)
First inode: 11
Inode size: 256
Required extra isize: 32
Desired extra isize: 32
Journal inode: 8
Default directory hash: half_md4
Directory Hash Seed: aeb82a13-d56b-4342-809f-47e69117f8e4
Journal backup: inode blocks
Checksum type: crc32c
Checksum: 0x65bc6c6aroot@raspberrypi:~# mount
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
proc on /proc type proc (rw,relatime)
udev on /dev type devtmpfs (rw,nosuid,relatime,size=1893568k,nr_inodes=118348,mode=755)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
tmpfs on /run type tmpfs (rw,nosuid,nodev,noexec,relatime,size=413936k,mode=755)
/dev/mmcblk0p2 on / type ext4 (rw,relatime)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
tmpfs on /dev/shm type tmpfs (rw,nosuid,nodev)
tmpfs on /run/lock type tmpfs (rw,nosuid,nodev,noexec,relatime,size=5120k)
cgroup2 on /sys/fs/cgroup type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate,memory_recursiveprot)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
bpf on /sys/fs/bpf type bpf (rw,nosuid,nodev,noexec,relatime,mode=700)
systemd-1 on /proc/sys/fs/binfmt_misc type autofs (rw,relatime,fd=29,pgrp=1,timeout=0,minproto=5,maxproto=5,direct,pipe_ino=13315)
tracefs on /sys/kernel/tracing type tracefs (rw,nosuid,nodev,noexec,relatime)
debugfs on /sys/kernel/debug type debugfs (rw,nosuid,nodev,noexec,relatime)
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime)
fusectl on /sys/fs/fuse/connections type fusectl (rw,nosuid,nodev,noexec,relatime)
configfs on /sys/kernel/config type configfs (rw,nosuid,nodev,noexec,relatime)
ramfs on /run/credentials/systemd-sysusers.service type ramfs (ro,nosuid,nodev,noexec,relatime,mode=700)
ramfs on /run/credentials/systemd-sysctl.service type ramfs (ro,nosuid,nodev,noexec,relatime,mode=700)
ramfs on /run/credentials/systemd-tmpfiles-setup-dev.service type ramfs (ro,nosuid,nodev,noexec,relatime,mode=700)
/dev/mmcblk0p1 on /boot/firmware type vfat (rw,relatime,fmask=0022,dmask=0022,codepage=437,iocharset=ascii,shortname=mixed,errors=remount-ro)
ramfs on /run/credentials/systemd-tmpfiles-setup.service type ramfs (ro,nosuid,nodev,noexec,relatime,mode=700)
binfmt_misc on /proc/sys/fs/binfmt_misc type binfmt_misc (rw,nosuid,nodev,noexec,relatime)
sunrpc on /run/rpc_pipefs type rpc_pipefs (rw,relatime)
tmpfs on /run/user/1000 type tmpfs (rw,nosuid,nodev,relatime,size=413920k,nr_inodes=103480,mode=700,uid=1000,gid=1000)
gvfsd-fuse on /run/user/1000/gvfs type fuse.gvfsd-fuse (rw,nosuid,nodev,relatime,user_id=1000,group_id=1000)
portal on /run/user/1000/doc type fuse.portal (rw,nosuid,nodev,relatime,user_id=1000,group_id=1000)It's really hard to debug, the only requirement I found is that the fs has to support hard links.
wofferl
commented
11 months ago It's really hard to debug, the only requirement I found is that the fs has to support hard links.
I can't find anything problematic in the setup either.
I would start again with debugging through auditd, maybe the rule was not insert correctly, because I haven't found a way to start the server in debug mode or increase the server logging. I'm pretty sure, the error comes from writing the fixed index file to the backup datastore, but I have no clue why.
I can't reproduce this error on my system with this package build, so the best change to get help here is to ask in the official proxmox forum https://forum.proxmox.com/forums/proxmox-backup-installation-and-configuration.24/ or how you are planning to do it with an extra ssd.
Finn0811
commented
11 months ago I think the rule is working, because I see log messages when I manually create files in that folder.
I opened a thread over there, maybe it can be resolved with their help.
Thanks a lot for your help and ideas!
LufyCZ
commented
10 months ago Have just come across the same issue. Also, an RPi5, though the dest is a zfs mirror, not an ext4 fs. Works fine for container backups, only VMs don't work. Let me know if/how I can help.
Finn0811
commented
10 months ago I created a thread here: https://forum.proxmox.com/threads/400-bad-request-on-vm-backup.136824/
Unfortunately there are no replies, yet. I think they are not interested in solving the issue.
wofferl
commented
10 months ago Have just come across the same issue. Also, an RPi5, though the dest is a zfs mirror, not an ext4 fs. Works fine for container backups, only VMs don't work. Let me know if/how I can help.
Is this also a new install? Which versions have you tested?
wofferl
commented
10 months ago I created a thread here: https://forum.proxmox.com/threads/400-bad-request-on-vm-backup.136824/
Unfortunately there are no replies, yet. I think they are not interested in solving the issue.
The problem is that this seems to be a very specific problem with the Raspi 5. Proxmox itself does not offer arm64 packages and since it is not a general problem, help is difficult. Until someone can debug this problem on a Raspi 5 more accurately, no solution will be found.
I use it myself on Armbian with a Helios64 and test it on a Raspi 4 and so far there are no problems.
Maybe you can try different constellations (PBS versions, kernel, etc.) or try to find out with tools like audit or strace what exactly causes the "EINVAL: Invalid argument" error.
You could also try to compile the packages with the script by yourself on the Raspi5, it might make a difference.
Finn0811
commented
10 months ago Yeah I understand that they do not provide arm builds but with the rise of powerful arm VPS and the new raspberry pi 5 these builds are really cool.
I just compiled them now but the issue is still present.
root@raspberrypi:~# ls -ltr /root/proxmox-backupserver_3.1.2-2/proxmox-backup-arm64/packages
total 87932
-rw-r--r-- 1 root root 178472 Dec 4 19:47 pbs-i18n_3.1.4_all.deb
-rw-r--r-- 1 root root 2822536 Dec 4 19:47 libjs-extjs_7.0.0-4_all.deb
-rw-r--r-- 1 root root 8500 Dec 4 19:47 libjs-qrcodejs_1.20230525-pve1_all.deb
-rw-r--r-- 1 root root 129944 Dec 4 19:47 libproxmox-acme-plugins_1.5.0_all.deb
-rw-r--r-- 1 root root 210292 Dec 4 19:47 proxmox-widget-toolkit_4.1.3_all.deb
-rw-r--r-- 1 root root 4465692 Dec 20 23:55 proxmox-backup-docs_3.1.2-2_all.deb
-rw-r--r-- 1 root root 6417028 Dec 20 23:55 proxmox-backup-file-restore-dbgsym_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 3097036 Dec 20 23:55 proxmox-backup-client_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 3099860 Dec 20 23:55 proxmox-backup-file-restore_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 6341024 Dec 20 23:55 proxmox-backup-client-dbgsym_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 27641364 Dec 20 23:55 proxmox-backup-server_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 34838080 Dec 20 23:56 proxmox-backup-server-dbgsym_3.1.2-2_arm64.deb
-rw-r--r-- 1 root root 367864 Dec 20 23:58 proxmox-termproxy_1.0.1_arm64.deb
-rw-r--r-- 1 root root 352356 Dec 20 23:58 pve-xtermjs_5.3.0-2_all.deb
-rw-r--r-- 1 root root 15920 Dec 20 23:58 proxmox-mini-journalreader-dbgsym_1.4.0_arm64.deb
-rw-r--r-- 1 root root 7956 Dec 20 23:58 proxmox-mini-journalreader_1.4.0_arm64.deb
-rw-r--r-- 1 root root 5471 Dec 20 23:58 proxmox-mini-journalreader_1.4.0_arm64.buildinfo
-rw-r--r-- 1 root root 1584 Dec 20 23:58 proxmox-mini-journalreader_1.4.0_arm64.changesI even upgraded to the newest kernel:
root@raspberrypi:~# uname -r
6.1.68-v8-16k+Error:
2023-12-21T00:28:28.021237+01:00 raspberrypi proxmox-backup-proxy[975]: starting new backup on datastore 'fwpbs02' from ::ffff:192.168.255.1: "ns/fwpve01/vm/101/2023-12-20T23:28:27Z"
2023-12-21T00:28:28.045857+01:00 raspberrypi proxmox-backup-proxy[975]: GET /previous: 400 Bad Request: no valid previous backup
2023-12-21T00:28:28.071039+01:00 raspberrypi proxmox-backup-proxy[975]: POST /fixed_index: 400 Bad Request: EINVAL: Invalid argument
2023-12-21T00:28:28.093135+01:00 raspberrypi proxmox-backup-proxy[975]: backup ended and finish failed: backup ended but finished flag is not set.
2023-12-21T00:28:28.093176+01:00 raspberrypi proxmox-backup-proxy[975]: removing unfinished backup
2023-12-21T00:28:28.093216+01:00 raspberrypi raspberrypi proxmox-backup-proxy[975]: removing backup snapshot "/opt/fwpbs02/ns/fwpve01/vm/101/2023-12-20T23:28:27Z"Can you run following command during your attempt and look for the error there and post the corresponding lines or the complete output file.
But be aware that some lines contains your pbs username and password!
strace -f -p $(pidof proxmox-backup-proxy) -X verbose --output=pbs-proxy-trace.txt
wofferl
commented
10 months ago 6.1.68-v8-16k+
So it seems Raspi 5 uses 16k pagesizes kernel. This can of course cause problems Pi5 16K PageSize Kernel Incompatible Software #107 Was the kernel in the first post also a 16k kernel (getconf PAGESIZE)?
wofferl
commented
10 months ago From the docu (Raspberry Pi Documentation The config.txt file) the 6.1.0-rpi6-rpi-2712 is also a 16k kernel.
kernel ... The Raspberry Pi 5 firmware defaults to loading kernel_2712.img because this image contains optimisations specific to Raspberry Pi 5 (e.g. 16K page-size). If this file is not present then the common 64-bit kernel (kernel8.img) will be loaded instead.
So you have to install a 4k kernel on the raspi 5 for proxmox backup server to work.
Finn0811
commented
10 months ago Awesome, with kernel=kernel8.img in config.txt it now works!
2023-12-21T12:23:35.829739+01:00 raspberrypi proxmox-backup-proxy[978]: starting new backup on datastore 'fwpbs02' from ::ffff:192.168.255.1: "ns/fwpve01/vm/101/2023-12-21T11:23:35Z"
2023-12-21T12:23:35.856352+01:00 raspberrypi proxmox-backup-proxy[978]: GET /previous: 400 Bad Request: no valid previous backup
2023-12-21T12:23:35.878724+01:00 raspberrypi proxmox-backup-proxy[978]: created new fixed index 1 ("ns/fwpve01/vm/101/2023-12-21T11:23:35Z/drive-scsi0.img.fidx")
2023-12-21T12:23:35.961433+01:00 raspberrypi proxmox-backup-proxy[978]: add blob "/opt/fwpbs02/ns/fwpve01/vm/101/2023-12-21T11:23:35Z/qemu-server.conf.blob" (426 bytes, comp: 426)
[...]
2023-12-21T12:37:36.770433+01:00 raspberrypi proxmox-backup-proxy[978]: successfully finished backup
2023-12-21T12:37:36.792511+01:00 raspberrypi proxmox-backup-proxy[978]: backup finished successfully
2023-12-21T12:37:36.792924+01:00 raspberrypi proxmox-backup-proxy[978]: TASK OK
2023-12-21T12:37:38.051409+01:00 raspberrypi proxmox-backup-proxy[978]: Upload backup log to datastore 'fwpbs02', namespace 'fwpve01' vm/101/2023-12-21T11:23:35Z/client.log.blobThanks a lot @wofferl 😀
LufyCZ
commented
10 months ago Awesome, with kernel=kernel8.img in config.txt it now works!
2023-12-21T12:23:35.829739+01:00 raspberrypi proxmox-backup-proxy[978]: starting new backup on datastore 'fwpbs02' from ::ffff:192.168.255.1: "ns/fwpve01/vm/101/2023-12-21T11:23:35Z" 2023-12-21T12:23:35.856352+01:00 raspberrypi proxmox-backup-proxy[978]: GET /previous: 400 Bad Request: no valid previous backup 2023-12-21T12:23:35.878724+01:00 raspberrypi proxmox-backup-proxy[978]: created new fixed index 1 ("ns/fwpve01/vm/101/2023-12-21T11:23:35Z/drive-scsi0.img.fidx") 2023-12-21T12:23:35.961433+01:00 raspberrypi proxmox-backup-proxy[978]: add blob "/opt/fwpbs02/ns/fwpve01/vm/101/2023-12-21T11:23:35Z/qemu-server.conf.blob" (426 bytes, comp: 426) [...] 2023-12-21T12:37:36.770433+01:00 raspberrypi proxmox-backup-proxy[978]: successfully finished backup 2023-12-21T12:37:36.792511+01:00 raspberrypi proxmox-backup-proxy[978]: backup finished successfully 2023-12-21T12:37:36.792924+01:00 raspberrypi proxmox-backup-proxy[978]: TASK OK 2023-12-21T12:37:38.051409+01:00 raspberrypi proxmox-backup-proxy[978]: Upload backup log to datastore 'fwpbs02', namespace 'fwpve01' vm/101/2023-12-21T11:23:35Z/client.log.blobThanks a lot @wofferl 😀
Can confirm, adding this line works! Thanks
Backups won't work on a new installation on raspberry pi 5.
Did I miss something? :)