Logging and ZRAM

Tutorials & Examples
,
1

Now that ZRAM support has been implemented, I wanted to further improve memory management by implementing a logging strategy that logs all activity in daily logs. As a bonus, the approach depicted below will also reduce the amount of writes to the SD flash memory card.

Context

Since I’m running on a memory-constrained machine (Raspberry Pi 3B+ with 1GB or memory) and so far solely relying on an over-dimensioned SD card (32 GB flash memory card), I wanted to keep the live log on a ZRAM filesystem and store the compressed daily logs to an archive folder outside ZRAM.

Here’s what I did:

  1. Configure the log4j2 logging strategy (basically adding the daily log rotation and compression)
  2. Create the archive folder in a folder that is readable and writable for the openhabian user
  3. Create a cron job to move the daily archives from ZRAM to storage.

So let’s go step-by-step in the approach.

1. Configure the log4j2 logger to rotate the log files on a daily basis (this happens at midnight).

1.1. Edit the log4j2 logger configuration file
Edit the file located at /var/lib/openhab2/etc/org.ops4j.pax.logging.cfg and scroll to the file appender definitions. The first file appender reports to /var/log/openhab2/openhab.log:

# Rolling file appender
log4j2.appender.out.type = RollingRandomAccessFile
log4j2.appender.out.name = LOGFILE
log4j2.appender.out.fileName = ${openhab.logdir}/openhab.log
# Edit 1 (comment out 1 line): comment out the default logger strategy (add a '%i" suffix to each log):
#log4j2.appender.out.filePattern = ${openhab.logdir}/openhab.log.%i
# Edit 2 (add 1 line): store the archived log files in ${openhab.logdir}/archive/ in a date-based folder structure, and use gzip compression:
log4j2.appender.out.filePattern = ${openhab.logdir}/archive/%d{yyyy/MM}/openhab_%d{yyyy-MM-dd}_%i.log.gz
log4j2.appender.out.immediateFlush = true
log4j2.appender.out.append = true
log4j2.appender.out.layout.type = PatternLayout
log4j2.appender.out.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.out.policies.type = Policies
log4j2.appender.out.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.out.policies.size.size = 16MB
# Edit 3 (add 3 lines): define the time-based log rotation policy:
log4j2.appender.out.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.out.policies.time.interval = 1
log4j2.appender.out.policies.time.modulate = true

Likewise, update the event log appender and the audit log appender (and any other nonstandard appender you defined in your custom setup, e.g. Z-Wave log apppender, HomeKit log appender…):

# Event log appender
log4j2.appender.event.type = RollingRandomAccessFile
log4j2.appender.event.name = EVENT
log4j2.appender.event.fileName = ${openhab.logdir}/events.log
# Edit 1 (comment out 1 line): comment out the default logger strategy (add a '%i" suffix to each log):
#log4j2.appender.event.filePattern = ${openhab.logdir}/events.log.%i
# Edit 2 (add 1 line): store the archived log files in ${openhab.logdir}/archive/ in a date-based folder structure, and use gzip compression:
log4j2.appender.event.filePattern = ${openhab.logdir}/archive/%d{yyyy/MM}/events_%d{yyyy-MM-dd}_%i.log.gz
log4j2.appender.event.immediateFlush = true
log4j2.appender.event.append = true
log4j2.appender.event.layout.type = PatternLayout
log4j2.appender.event.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-26.26c] - %m%n
log4j2.appender.event.policies.type = Policies
log4j2.appender.event.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.event.policies.size.size = 16MB
# Edit 3 (add 3 lines): define the time-based log rotation policy:
log4j2.appender.event.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.event.policies.time.interval = 1
log4j2.appender.event.policies.time.modulate = true

# Audit file appender
log4j2.appender.audit.type = RollingRandomAccessFile
log4j2.appender.audit.name = AUDIT
log4j2.appender.audit.fileName = ${openhab.logdir}/audit.log
# Edit 1 (comment out 1 line): comment out the default logger strategy (add a '%i" suffix to each log):
#log4j2.appender.audit.filePattern = ${openhab.logdir}/audit.log.%i
# Edit 2 (add 1 line): store the archived log files in ${openhab.logdir}/archive/ in a date-based folder structure, and use gzip compression:
log4j2.appender.audit.filePattern = ${openhab.logdir}/archive/%d{yyyy/MM}/audit_%d{yyyy-MM}_%i.log.gz
log4j2.appender.audit.append = true
log4j2.appender.audit.layout.type = PatternLayout
log4j2.appender.audit.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-5.5p] [%-36.36c] - %m%n
log4j2.appender.audit.policies.type = Policies
log4j2.appender.audit.policies.size.type = SizeBasedTriggeringPolicy
log4j2.appender.audit.policies.size.size = 8MB
# Edit 3 (add 3 lines): define the time-based log rotation policy:
log4j2.appender.audit.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.audit.policies.time.interval = 1
log4j2.appender.audit.policies.time.modulate = true

2.2. Restart openHAB
Now restart openHAB to ensure the new log policy is active. Log in as openhabian user and type the following command:

$ sudo service openhab2 restart

2.3 Notes

  1. Since the audit log remains empty on my setup, I rotate it on a monthly basis (see the %d{yyyy/MM} and %d{yyyy-MM} patterns) whereas other log files are rotated daily (see the %d{yyyy-MM-dd} pattern).
  2. The archive subfolder and its year/month structure are automatically created when the daily (or monthly) log is rotated. You don’t have to create this folder structure!

2. Create the archive folder in a folder that is readable and writable for the openhabian user

One important limitation with the log4j2 logger is that it cannot compress archived logs unless they are stored on the same filesystem mount point. With the current ZRAM configuration, the entire /var/log/ folder is now managed by ZRAM. This leads to 2 implementation options:

  1. You can live with uncompressed logs which can eat up a lot of space after a certain amount of time, and while doing so, your SD card will wear out faster.
  2. You let the log4j2 logger create compressed log archives in a sub folder in /var/log/openhab2/ and rely on other tools to move these to another location

In the current tutorial, we opt for option 2. The location where we will store the archived logs is a folder in the home directory of the openhabian user: /home/openhabian/openhab-log-archive. It is created by logging in as openhabian user and typing the following command:

$ mkdir ~/openhab-log-archive

In the next step we will relocate the daily log archives to this folder.

3. Create a cron job to move the daily archives from ZRAM to storage.

In this step we will schedule 2 jobs for the openhabian user:

  1. Move the compressed archives from the ZRAM-controlled folder to the log archive folder from the openhabian user
  2. Prune empty folders from the ZRAM-controlled archive folder

Both jobs will be run at a different point in time. We will now add 2 cron jobs for the openhabian user. To edit the cron job, log in as the openhabian user and type:

$ crontab -e

NOTE: By default the nano editor will be used. If you want to use a different editor, then you should first define the VISUAL shell variable. I’m a vi user so I would type:

$ VISUAL=vim crontab -e

At the bottom of the cron file, add the following 4 lines:

# Move openHAB backup archives to an archive folder of the openhabian user. Check hourly at 4 minutes past the hour.
4 * * * * /usr/bin/rsync -a --whole-file --remove-source-files /var/log/openhab2/archive/ /home/openhabian/openhab-log-archive
# Prune empty folders after having moved log archives. Check hourly on the 1st of the month at 6 minutes past the hour.
6 * 1 * * /usr/bin/find /var/log/openhab2/archive/ -depth -empty -exec rmdir "{}" ';'

Save the cron job, and you’re done.

Benefits

This approach has the following benefits:

  1. Reduce ZRAM usage by relocating archive log files to flash storage (or any other storage rsync can access, e.g. on a NAS or on cloud storage).
  2. Increase the lifespan of your SD memory card by reducing the number of writes.

Suggestions
A similar approach can also be used for relocating e.g. openHAB backups etc.

Final words
Have fun!

2 Likes
2

Thanks for documenting. I’d give this another thought or two, though.
ZRAM actually can/will automatically move logfiles to another (non-ZRAM) directory if the mount is declared to be of log type and the target dir is given in /etc/ztab.
Frankly I am not 100% sure of the exact trigger to this procedure. Haven’t managed to find out so far, maybe you could evaluate that ?
I’d suggest to better make use of that than to put your own mechanics on top because ‘log’ is the default for /var/log in openHABian so it’ll apply that anyway regardless of what you proposed here.

3

I wasn’t aware of this, and I have also to admit that the ZRAM documentation is sparse in some parts.

All I could find so far, is that you can define a log rotation policy when defining a location for storing old logs (oldlog_dir). But so far I couldn’t find how this is done in practice.

The current ZRAM configuration on openHABian does not (yet) leaves the oldlog_dir blank, hence this feature is currently not active in the default setup.

Reason for this, is probably that it is difficult to define a one-size-fits-all approach since the default logging is size-based, not time-based, and you may define your own log rotation policies.

From this zram issue I infer one could define their own (simple) file-based logrotate policy in /etc/logrotate.d/ (instead of defining your own log rotation policy in log4j2). For more complex policies, they also suggest writing your own implementation.

4

Hello,
I’m trying to do the same in my OpenHab, but instead files listed with dates in names I get something like this:
image

Here’s my config:

# Event log appender
log4j2.appender.event.type = RollingRandomAccessFile
log4j2.appender.event.name = EVENT
log4j2.appender.event.fileName = ${openhab.logdir}/events.log
log4j2.appender.event.filePattern = ${openhab.logdir}/events.log.%d{yyyy-MM-dd-HH:mm}_%i
log4j2.appender.event.immediateFlush = true
log4j2.appender.event.append = true
log4j2.appender.event.layout.type = PatternLayout
log4j2.appender.event.layout.pattern = %d{yyyy-MM-dd HH:mm:ss.SSS} [%-26.26c] - %m%n
log4j2.appender.event.policies.type = Policies
# log4j2.appender.event.policies.size.type = SizeBasedTriggeringPolicy
# log4j2.appender.event.policies.size.size = 10MB
log4j2.appender.event.policies.time.type = TimeBasedTriggeringPolicy
log4j2.appender.event.policies.time.interval = 1
log4j2.appender.event.policies.time.modulate = true

There are HH:mm for tests, to make a copy every minute.

5

to do what? You show a screendump but it’s totally unclear what you want to say by that.
Messing with log4j2 will affect openHAB logging but that’s unrelated to ZRAM (unless you put the ZRAM/logrotate mechanism on top).

It is active in my current ZRAM implementation. Yes docs are sparse but according to the link you gave it’s standard logrotate. On ZRAM install, it creates this:

[16:16:11] openhabian@openhabianpi:/etc/logrotate.d$ cat zram-config
/usr/local/share/zram-config/log/zram-config.log
{
        rotate 4
        weekly
        missingok
        notifempty
        compress
        delaycompress
        sharedscripts

}
6

When inspecting /usr/local/share/zram-config/log/zram-config.log it appears that the logrotate ruleonly applies to zram-related log entries reported in /usr/local/share/zram-config/log/zram-config.log…

7

Yes. If you’re looking for what rotates whatever you define in /etc/ztab, that’s /etc/logrotate.d/00_oldlog.
A little incomplete by the original author so feel free to come up with a patch for that.
I tried this myself but haven’t finished, too busy on openHABian.

[21:24:00] openhabian@openhabianpi:/etc/logrotate.d$ more 00_oldlog
daily
notifempty
#olddir /volatile/oldlogs
olddir /log.bind
nocompress
createolddir 755 root root
renamecopy

/var/log/openhab2/openhab.log.* {
        olddir /log.bind/openhab2
}
/var/log/openhab2/events.log.* {
        olddir /log.bind/openhab2
}