Huge sparse files are not properly handled

[gregoo]

/var/log contains sparse file like lastlog, faillog that are indexed with the UID. When you are using an external authentication system (like FreeIPA) UIDs can be huge (145000000+), making the lastlog and faillog appear huge as well.

This morning I woke up with a full disk after enrolling my Pi into our FreeIPA system. Checking the logs (and using -s to display the sparse file actual size), I noticed that the log2ram does not recreate the sparse files as such.

gregory@pi:/$ ls -lhs /var/hdd.log/lastlog
3.3G -rw-rw-r-- 1 root utmp 3.3G Nov  3 11:21 /var/hdd.log/lastlog
gregory@pi:/$ ls -lhs /var/log/lastlog
296K -rw-rw-r-- 1 root utmp 41G Nov  3 10:36 /var/log/lastlog

The disk version is only 3.3G because I aborted log2ram write when I saw it was actually creating all the data. I've tried removing /var/hdd.log/lastlog, adding --sparse to rsync (3.1.3+ can handle both --inplace and --sparse at the same time), and launching log2ram write and it seems to be working.

During copy:

gregory@pi:/var/hdd.log$ ls -lhs lastlog
4.0K -rw------- 1 root root 290K Nov  3 11:28 lastlog

After copy (file is only 8KB ?):

gregory@pi:/var/hdd.log$ ls -lhs lastlog
8.0K -rw-rw-r-- 1 root utmp 41G Nov  3 10:36 lastlog

The copy seems complete, when I chroot in an environment where /var/hdd.log/ is actually /var/log/, I'm seeing the proper entry, and the system does not complain about diskspace anymore.

No chroot (RAM /var/log):

root@pi:~# id gregory
uid=145200007(gregory) gid=145200007(gregory) groups=145200007(gregory),...
root@pi:~# lastlog -u gregory
Username         Port     From             Latest
gregory          pts/2    176.185.---.---   Tue Nov  3 11:32:23 +0000 2020
root@pi:~# df -h
Filesystem      Size  Used Avail Use% Mounted on
udev            1.9G     0  1.9G   0% /dev
tmpfs           380M  2.7M  377M   1% /run
/dev/mmcblk0p2  7.1G  2.0G  4.9G  29% /
tmpfs           1.9G     0  1.9G   0% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs           1.9G     0  1.9G   0% /sys/fs/cgroup
/dev/mmcblk0p1  253M   97M  156M  39% /boot/firmware
log2ram         250M   47M  204M  19% /var/log
tmpfs           380M     0  380M   0% /run/user/1000
tmpfs           380M     0  380M   0% /run/user/145200007

Chroot (/var/hdd.log):

root@pi:/# id gregory
uid=145200007(gregory) gid=145200007(gregory) groups=145200007(gregory),...
root@pi:/# lastlog -u gregory
Username         Port     From             Latest
gregory          pts/2    176.185.---.---   Tue Nov  3 11:32:23 +0000 2020
root@pi:/# strace lastlog -u gregory 2>&1 | grep /var/log
openat(AT_FDCWD, "/var/log/lastlog", O_RDONLY) = 5
root@pi:/# df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/mmcblk0p2  7.1G  2.0G  4.9G  29% /etc
udev            1.9G     0  1.9G   0% /dev
tmpfs           380M  2.7M  377M   1% /run

However, when the file already exists, it doesn't seem to work.

root@pi:~# log2ram write
building file list ... done
auth.log
kern.log
lastlog
log2ram.log
syslog
wtmp
journal/c5a4a8e5bf5e442db85643dc7156b2ea/
journal/c5a4a8e5bf5e442db85643dc7156b2ea/system.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/system@6f66776ccb6643e4865d5263b7d9d339-0000000000028746-0005b3317bd835e3.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/user-1000.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/user-145200000.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/user-145200000@e96f45f36e1f40b59c5fe3e70f81fce3-0000000000028762-0005b3317bd8d473.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/user-145200007.journal
journal/c5a4a8e5bf5e442db85643dc7156b2ea/user-145200007@57a9e926b23b4346a68fa3623f88455a-0000000000028b40-0005b33223b0a378.journal
rsync: write failed on "/var/hdd.log/lastlog": Success (0)
rsync error: error in file IO (code 11) at receiver.c(374) [receiver=3.1.3]

The error message is cryptic on client side (failed with Success (0)), the receiver complains about no space left on disk (code 11) and searching yields only this Fedora bug report: https://bugzilla.redhat.com/show_bug.cgi?id=1542513.

The only viable option for me was to fallback to cp (which I couldn't do simply by uninstalling rsync because it is required by ubuntu-standard which shouldn't be removed). I ended up restoring your USE_RSYNC flag so that I could manually override rsync.

---

Following are some errors I encountered but cannot reproduce entries:

• Probably without --sparse

rsync: write failed on "/var/hdd.log/lastlog": No space left on device (28)
rsync error: error in file IO (code 11) at receiver.c(374) [receiver=3.1.3]

• Second time with --sparse

rsync: write failed on "/var/hdd.log/lastlog": Success (0)
rsync error: error in file IO (code 11) at receiver.c(374) [receiver=3.1.3]

[SeeJayEmm]

Has any progress been made on this? I'm in a similar situation.

[bmatheny]

Running into this as well. I zerod the file and then updated LASTLOG_UID_MAX in /etc/login.defs. Not a great option but it looks like it worked? Maybe.