monome / norns-image

79 stars 16 forks source link

daemon.log fills up with xrun log lines #96

Open ambv opened 2 years ago

ambv commented 2 years ago

On OG aluminium Norns with 4GB of storage, the new image takes up quite a bit of space. There's less than a 1GB left for user data after a clean install so it would be nice if we could somehow make logging more efficient.

I'm looking at daemon.log and find it pretty big after ~12 hours of runtime. It's 66MB with a number of repeated lines (sorted here):

 258721 norns jackd[384]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
 246914 norns jackd[384]: JackEngine::XRun: client = softcut was not finished, state = Running
  76709 norns jackd[453]: JackAudioDriver::ProcessGraphAsyncMaster: Process error
  73652 norns jackd[453]: JackEngine::XRun: client = softcut was not finished, state = Running
   6375 norns jackd[384]: JackEngine::XRun: client = softcut was not finished, state = Triggered
   5636 norns jackd[384]: JackEngine::XRun: client softcut finished after current callback
   2804 norns ws-wrapper[2550]: station  0  queing next file  1  of  1
   2804 norns ws-wrapper[2550]: station 0 playing file /dev/shm/weather.wav
   1937 norns ws-wrapper[2550]: MP3.start: command to execute is:
   1675 norns jackd[453]: JackEngine::XRun: client = softcut was not finished, state = Triggered

As you can see, there's 250 thousand xruns reported. This log survives a restart.

tehn commented 2 years ago

image setup is supposed to limit log sizes, so something is not working correctly since we moved to bullseye. if you spot the config problem please let us know.

ambv commented 2 years ago

I discovered that logrotate isn't running, it's failing to start with:

Jun 16 09:53:21 norns systemd[1]: Starting Rotate log files...
Jun 16 09:53:21 norns logrotate[866]: error: /etc/logrotate.conf:18 duplicate log entry for /var/log/wtmp
Jun 16 09:53:21 norns logrotate[866]: error: /etc/logrotate.conf:25 duplicate log entry for /var/log/btmp
Jun 16 09:53:21 norns systemd[1]: logrotate.service: Main process exited, code=exited, status=1/FAILURE
Jun 16 09:53:21 norns systemd[1]: logrotate.service: Failed with result 'exit-code'.
Jun 16 09:53:21 norns systemd[1]: Failed to start Rotate log files.

This is on a clean install of the newest image (+update on device).

ambv commented 2 years ago

The problem is that logrotate.conf includes sections for wtmp and btmp but there are also separate files for those logs in logrotate.d so they end up being duplicated.

simonvanderveldt commented 2 years ago

There should be no reason for logrotate because there should be no log files, all logs should be taken care of by systemd/the journal. If there's a log file somewhere that should probably be fixed to make sure the logs end up in the journal.

ambv commented 2 years ago

The log this issue is about is a file under the path /var/log/daemon.log. Don't you see one on your installations?

In my case there are also auth.log, debug, dpkg.log, kern.log, messages, syslog, user.log, and wtmp. All of which see use.

simonvanderveldt commented 2 years ago

Maybe something went wrong or was changed in the config with the switch/upgrade to Debian Buster?

ambv commented 2 years ago

Likely. This is somewhat high priority because it turns out daemon.log fills up also with regular operation, like when receiving OSC messages. I filed a separate issue for that.