armbian-ramlog problems and possible improvements

[jba]

On my odroid hc2 with armbian/bullseye I found some of the logs (both in /var/log and /var/log.hdd) empty, while they should have some contens (i.e. afpd.log, kern.log, user.log, ...).

 

The empty files all have the timestamp of a run of armbian-ramlog at a recent reboot. In armbian-ramlog.log I found this for the run that created the empty files:

 

rsync: [receiver] write failed on "/var/log/journal/0d4b1c13b9a14b6d9c746402b7d7ef6f/user-1000@0005d37f46f9961b-23c015a66b68d086.journal~": No space left on device (28)
rsync error: error in file IO (code 11) at receiver.c(378) [receiver=3.2.3]
rsync: [sender] write error: Broken pipe (32)

 

Seems that journal has become too big to fit on the log/ramdisk. That is strange, as I defined a maximum of 20MB for the journal and the ramdisk has 50MB.

 

I guess this is what happened: When syncing to sd armbian-ramlog uses rsync without --delete. So if some older files have been already delete by journald (because of the 20 MB limit) on the ramdisk, they will still stay in the log on sd. Therefore the journal on the sd will become bigger and bigger. Which is not a problem because there is plenty of space on the sd. However, when rebooting everything is copied from the sd to the ramdisk. Including the bloated journal. Thus the ramdisk is full and additional files will not fit (see error message from rsync).

 

I think in this case rsync just creates empty files and that is the reason for my empty logs. And on next sync the empty files are copied back to sd so both versions are empty.

 

There is another potential problem I see in the implementation of armbian-ramlog: on reboot only recent files (so no *.gz or *.[0-9]) are copied to ramdisk. After som runtime logrotate will rotate the logs and create new *.gz or *.[0-9]. However, these might already exist on the sd. They will be overwritten when the logs are written back to sd. So you loose old logs.

 

I think both problems are due to the fact that simple rsync is used without --delete and without copying even the old files to the ramdisk. To overcome these problems I see two ways:

 

• use rsync --delete and dont exclude *.gz and *.[0-9]. Then the ramdisk holds all logs and when copying to sd nothing is lost. But this may requier a bigger ramdisk
• dont use rsync but use an overlay fs instead. I found this discussion on the topic. The described solution looks superior to me than what we are using now:
  https://unix.stackexchange.com/questions/424341/mount-var-logs-as-tmpfs-with-help-of-overlayfs-to-save-changes-sometimes

 

What do you think about it? Would it make sense to use an overlay fs?

 

I am not that deep into linux hacking and therefore are not sure if I would be able to implement it in a nice way. But I would like to support this process and do some tasks.

 

Regards,

jba

[jba]

I did some testing with overlayfs as described in the link. It worked fine but I also found out, that writing to the lowerdir (in our case the version on the sd) is not permitted by overlayfs. You can do so, it worked in a test, but its no guaranteed to work always. Seems it was designed for ro lowerdirs only:

 

Zitat

Changes to the underlying filesystems while part of a mounted overlay filesystem are not allowed. If the underlying filesystem is changed, the behavior of the overlay is undefined, though it will not result in a crash or deadlock.

 

So it is not a good idea to use it this way.

 

What could be done is having to directories on sd. One is used to hold the lowerdir and will not be changed while the ramdisk is mounted as an overlay. The other one (backup) holds the changes and is updated once per day and on shutdown. On next boot all files are copied from the backup to the lowerdir before the overlay is setup. However, the only benefit of this approach to the solution I now use (see below) is that we need a smaller ramdisk (as it only holds the changes) and safe some ram.

 

What I did in the end is modifying armbian-ramlog so that

• all syncs are done with the option --delete
• *.gz, *.xz, '*.[0-9] are no longer excluded from the rsync

Now log.hdd is an exact copy of log. Therefore the ramdisk needs be somehow bigger. I increased the size to 70 MB which seems to work.

 

Any opinion on that? What about including it in the package?

 

jba

[jba]

Now I have a solution that works. The hole thing seems extremely complicated to me. I did not find out all the tricks how logrotate, armbian-ramlog and maybe other functions work together. But the problem I had is now clear to me:

 

Armbian copies current logs ad midnight from /var/log to /var/log.hdd. There they are rotated by logrotate. That works (at least for logs armbian is aware of).  However, /var/log/journal (by journald) is not covered by logrotate. It does its own cleaning up in /var/log/journal. So /var/log.hdd/journal is keeping all the old files and gets bigger and bigger. On my system it increases by 10 MB per day. So after some days, /var/log.hdd gets bigger than 50 MB, which is the size of the ramdisk used for /var/log. Which becomes a problem on next reboot because then everything from /var/log.hdd is copied to /var/log which is too small. Therefore not all logs can be copied and get get lost in the end.
 

My proposed solution is to do a second sync in syncToDisk to sync /var/log/journal to /var/log.hdd/journal and uses the --delete option. This way, everything that was deleted in /var/log/journal will also be deleted in /var/log.hdd/journal. Now, /var/log.hdd/journal grows no longer. Here is the patch:

 

jba@lana:/lib/armbian$ diff armbian-ramlog armbian-ramlog.orig 
56,62d55
< 
<               # jba 2022-03-15
<               ${NoCache} rsync -aXWv \
<                               --delete \
<                               --links \
<                               ${RAM_LOG}journal/ ${HDD_LOG}journal 2>&1 | $LOG_OUTPUT
< 

 

This works fine on my system.

 

What do you think about it? can it be incorporated in official armbian-ramlog? How can I post a bug report and proposal?

 

jba

[lanefu]

29 minutes ago, jba said:

What do you think about it? can it be incorporated in official armbian-ramlog? How can I post a bug report and proposal?

Let's keep the conversation going..

Code for related components here:

https://github.com/armbian/build/tree/master/packages/bsp/common/usr/lib/armbian

The truncatelogs script does address journald, but to your point it might not be enough.

 

Take a look at the history and blame log to see if there's some useful context

https://github.com/armbian/build/blame/master/packages/bsp/common/usr/lib/armbian/armbian-ramlog
 

[jba]

Zitat

The truncatelogs script does address journald, but to your point it might not be enough.

 

Correct. The cleanup i done in /var/log/journal (at least thats how I understand the statement). Deletion of files is never propagated to /var/log.hdd/journal.

 

In armbian-truncate-jobs maximum size of journal is 5MB. For journald it is defined as 20 MB. And a size of about 20 MB is what I normally see. I would expect it to be the lower value as in armbian-truncate-logs. Why is this not the case?

 

 

Zitat

Take a look at the history and blame log to see if there's some useful context

https://github.com/armbian/build/blame/master/packages/bsp/common/usr/lib/armbian/armbian-ramlog

 

There was a --delete in an older version, but for the complete /var/log. This wouldn't work with the other scripts as they interplay today. The --delete was removed 3 years ago.

 

jba

[lanefu]

9 hours ago, jba said:

Why is this not the case?

It was probably not considered.

 

 

[jba]

Am 21.3.2022 um 00:33 schrieb lanefu:

It was probably not considered.

 

 

You are right, as my /var/log is less than 75 % full this part of the script is not executed.

 

So, what can I do with my "patch" (I know its trivial but it solves a problem that may exist on a lot of armbian systems)? Can I send it anywhere to get checked?

 

jba

[Cucaracha]

I have the same issue and I've tested the script with the --delete option. The change solved my issue. Before I had about 74 MB in /var/log.hdd/journal. After the change and executing the cronjob I have about 7 MB now. So the ramdisk will not be overfilled anymore.

 

I've created a pull request with this small change: https://github.com/armbian/build/pull/3779

[lanefu]

On 5/14/2022 at 4:34 AM, Cucaracha said:

I have the same issue and I've tested the script with the --delete option. The change solved my issue. Before I had about 74 MB in /var/log.hdd/journal. After the change and executing the cronjob I have about 7 MB now. So the ramdisk will not be overfilled anymore.

 

I've created a pull request with this small change: https://github.com/armbian/build/pull/3779

thank you!  merged!

[hege]

I've been hit with zram/journald problems too. In the end I ended up disabling zram altogether. Journald by default stores log messages in ram (in /var/run/systemd/journal which is using the tmpfs at /run), and only flushes them to /var/log/journal every 5 minutes by default (+flushing every emergency log events as they occur). I disabled journald logging to syslog, which means my /var/log is now on eMMC, but still not written at too high of a rate to cause wear. I believe with the correct journald settings, zram will become completely unnecessary.

[arnaudf]

Hello,

 

I wonder if there other improvements. Indeed I did some changes to have thing working better.

(Using Armbian 23.8.1 on Rockpro64)

 

For example :

 

- In journald.conf : had to set Storage as "volatile" instead of "auto". If not there is truncation of journald content at every midnight log rotation.

I saw that some armbian-ramlog script steps depends on "volatile" Storage value.

EDIT 23/01/2024 : in fact with "volatile" journal logs are never flushed to persistent storage. So I returned back to "auto" but needed to amend postrotate (see below).

 

- In armbian-ramlog postrotate, I have done these changes :

 postrotate)
        cd /var/log.hdd/
        #find . -type f -print | grep -E -v "(\.gz|\.xz|\.[0-9]|armbian-ramlog)" | while IFS= read -r  file
        find . -type f -printf '%P\n' | grep -E -v "(\.gz|\.xz|\.[0-9]|armbian-ramlog)" | while IFS= read -r  file
        do
                dest="/var/log/$file"
                # Fix: journal path exclusion
                if [[ "$dest" == */journal* ]] && [ -L $RAM_LOG/journal ]; then continue; fi
                # Fix: create full directory path if not exists
                if [ ! -d ${dest%/*} ]; then mkdir -p ${dest%/*}; fi

                cat $file > $dest
        done
        ;;

 

So basically :

- slightly modified the find action ( -printf '%P\n') to remove the leading dot
- test and skip current file if $dest contains "/journal" and $RAM_LOG/journal is a link (to /var/log.hdd/journal). This leads to not overwrite journal files, so no truncation
- added an mkdir -p so the full path is created if needed (if not there could be some errors with "deep" paths)

 

I could submit a PR if needed.

 

Also in armbian-truncate-log I see this line :

[ -d /var/log.hdd/journal ] && find /var/log.hdd/journal -ctime 1 \( -name '*@*' -o -name '*~' \)  -delete

 

Why is it needed/done ? IMHO this could lead to delete history on ssd (permanent) storage although this truncation script seems to be purported for cleaning in-memory log partition.

The path should be /var/log/ instead of /var.log.hdd, I assume (?)

Edited January 23 by arnaudf