savonet / liquidsoap-daemon

Daemonization scripts for liquidsoap
37 stars 11 forks source link

Logging stopped after log file rotation (logrotate) #31

Open nuess0r opened 2 years ago

nuess0r commented 2 years ago

Describe the bug As mentioned in my other bug report liquidsoap stopped logging after log file rotation.

Between the older log files I rebootet the system to test systemd scripts.

# ls -l /var/log/liquidsoap/
insgesamt 528
-rw------- 1 liquidsoap liquidsoap      0 16. Sep 00:00 radio.log
-rw------- 1 liquidsoap liquidsoap 494273 15. Sep 23:57 radio.log.1.gz
-rw------- 1 liquidsoap liquidsoap  24307  6. Sep 23:59 radio.log.2.gz
-rw------- 1 liquidsoap liquidsoap  17525 20. Jul 23:49 radio.log.3.gz

When I see this correct, the logrotate config is the one that was provided by the apt package:

# ls -l /etc/logrotate.d/liquidsoap 
-rw-r--r-- 1 root root 321  1. Sep 20:26 /etc/logrotate.d/liquidsoap
# cat /etc/logrotate.d/liquidsoap 
/var/log/liquidsoap/*.log {
  compress
  rotate 5
  size 300k
  missingok
  notifempty
  sharedscripts
  postrotate
    for liq in /var/run/liquidsoap/*.pid ; do
      if test $liq != '/var/run/liquidsoap/*.pid' ; then
        start-stop-daemon --stop --signal USR1 --quiet --pidfile $liq
      fi
    done
  endscript
}

To Reproduce logrotate --force /etc/logrotate.d/liquidsoap

Expected behavior Continue logging with new log file

Version details

Install method apt packages from https://github.com/savonet/liquidsoap/releases

Kerosel commented 2 years ago

I ran into this when I was running official builds. Right now I'm on one of the "dailies" that doesn't have systemV/systemD scripts (as far as I can tell?) so I'm running my LS script in a "screen" and logging to /tmp...

Anyway, I found the logging wasn't stopping, it just wasn't jumping to the new log file (still logging to "radio.liq.1" in your case). The problem turned out to be a change in start-stop-daemon to make it more secure: it refuses to work with a PID file that doesn't match the user it's running under. It also gets huffy about working with a PID file that has read/write permissions for anyone other than the owner. Makes sense to me, keeps a random person from tampering with a PID file to make start-stop-daemon affect a different process. Imagine if you changed your radio.liq PID to someone else's shell and then commanded SystemV to shut down your radio stream...

The fix that worked for me was to modify the line with start-stop-daemon:

...
 postrotate
    for liq in /var/run/liquidsoap/*.pid ; do
      if test $liq != '/var/run/liquidsoap/*.pid' ; then
        sudo -u liquidsoap start-stop-daemon -c liquidsoap --stop --signal USR1 --quiet --pidfile $liq
      fi
    done
  endscript

This makes start-stop-daemon run under the "liquidsoap" user (the sudo) and also change to that user when doing work (-c liquidsoap). Now the PID file it creates/works with is owned by "liquidsoap" and that matches the user that start-stop-daemon is running under. At that point, logs began rotating normally and I had no issues with it.

Unfortunately I don't have the init.d scripts anymore (they were removed when I uninstalled the official packages) but I might have done the same thing to the start-stop-daemon lines in it as well. Check your PID file (/run/liquidsoap/ maybe?) and if it's owned by "liquidsoap" and only has r/w permissions for the owner, the above change to the logrotate script may be all you need.

Hope this helps and maybe can prompt an official solution to deal with the updated start-stop-daemon.

nuess0r commented 2 years ago

@Kerosel thanks a lot for your explanation and how you fixed it.

Now my problem looks very different than before :-)

I'm using systemd and the service script provided by radio RaBe and therefore I don't have a PID file at all. No surprise the script fails...

I've to check how to send a signal to a daemon controlled by systemd.

Kerosel commented 2 years ago

@nuess0r, I see what you mean. I did my research and I see systemd keeps track of PIDs itself and doesn't use files in /run.

I checked how to send a signal to a daemon with systemd and it turns out it goes like this:

systemctl kill --signal <signal> liquidsoap@aviaryradio.service

So I changed the logrotate config to send SIGUSR1 to all liquidsoap instances...

[...]
  sharedscripts
  postrotate
    sudo systemctl kill --signal SIGUSR1 liquidsoap@\*.service
  endscript

And it works! My logs rotated and the output went to the newly created log file. I'd say give that change a try in the liquidsoap logrotate config and see if it works for you too. I suppose it may not need the "sudo" if logrotate already runs as root... but I'll have to wait for my log to grow again before I can check that.

UPDATE: It does work without the "sudo" in the logrotate script. Been rotating without issue for a few weeks now on my system.

nuess0r commented 2 years ago

I checked how to send a signal to a daemon with systemd and it turns out it goes like this: [...] UPDATE: It does work without the "sudo" in the logrotate script. Been rotating without issue for a few weeks now on my system.

I also changed it on my system and it works as intended. Thanks a lot!

The question for upstream would be how to detect in a robust way if the older script part or the systemd script part shall be executed.

toots commented 2 years ago

Thanks for investigating this y'all! I have changed our daemonization scripts to send the logrotate signal using kill and sudo. Any chance y'all could give it a try? It's here: https://github.com/savonet/liquidsoap-daemon

toots commented 2 years ago

I'm moving this there too.

Kerosel commented 2 years ago

@toots, I haven't tried the new logrotate script but I think I see a problem with it. The original issue that @nuess0r pointed out is that systemd doesn't even make a PID file anymore because it tracks all the process IDs internally. That's why it required "systemctl kill..." to let systemd handle sending the signal to the appropriate process. I believe the logrotate script as written currently will work with init.d but not with systemd.

I'm still wrapping my head around how the "daemonize" script sets everything up, but it may necessary to have two different logrotate scripts (or at least two different post-rotate sections) depending on if the user is setting up for init.d or systemd.