Gentoo Forums
Gentoo Forums
Gentoo Forums
Quick Search: in
Logrotate broke syslog-ng
View unanswered posts
View posts from last 24 hours

 
Reply to topic    Gentoo Forums Forum Index Networking & Security
View previous topic :: View next topic  
Author Message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Sun May 08, 2022 9:30 am    Post subject: Logrotate broke syslog-ng Reply with quote

Hi All,

During last night logrotate did it's job and unfortunately that broke syslog-ng in the lxc that is my mailserver (postfix/dovecot). That might not immediately be the end of the world, but it caused all processes that try to log to hang. As a result i could not log in via ssh, could not restart any process, mails could not be delivered and cron jobs stalled.

Some checks i have done during this situation:
- Disk space was ok (it's a 10GB luks volume, 2.5GB free)
- The rotation in itself seemed to be successful, the old /var/log/messages got suffixed with the date and a new /var/log/messages was created with 0 bytes
- syslog-ng was running, but the pid number was very low, which might be an indication it didn't actually stop (not conclusive of course since PIDs get reused)
- I ran strace -f /etc/init.d/sshd restart which showed start-stop-daemon to hang on opening the /dev/log socket
- As soon as i manually killed syslog-ng all hanging processes continued to do what they intended to do
- After /etc/init.d/syslog-ng zap i could /etc/init.d/syslog-ng start without issues or warnings
- A logrotate was also done a week ago with all software at the same versions and there was no problem that time

My syslog-ng setup is very basic, this is the version and use flags:
Code:

[ebuild   R    ] app-admin/syslog-ng-3.35.1::gentoo  USE="ipv6 -amqp -caps -dbi -geoip2 -http -json -kafka -mongodb -pacct -python -redis -smtp -snmp -spoof-source -systemd -tcpd -test" PYTHON_SINGLE_TARGET="python3_9 -python3_8 -python3_10" 0 KiB

It's configuration is default (comments removed for brevity):
Code:

@version: 3.35

@include "scl.conf"

options {
   threaded(yes);
   chain_hostnames(no);
   stats_freq(43200);
   mark_freq(3600);
};

source src { system(); internal(); };
destination messages { file("/var/log/messages"); };
log { source(src); destination(messages); };

Has anyone else seen similar problems? And maybe more important: Is there a way to prevent it from happening?
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
freke
l33t
l33t


Joined: 23 Jan 2003
Posts: 976
Location: Somewhere in Denmark

PostPosted: Sun May 08, 2022 3:31 pm    Post subject: Reply with quote

Never experienced that - you do have something like
Code:
/var/log/messages {
    delaycompress
    missingok
    sharedscripts
    postrotate
        /etc/init.d/syslog-ng reload > /dev/null 2>&1 || true
    endscript
}
somewhere in your logrotate configuration?
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Sun May 08, 2022 5:41 pm    Post subject: Reply with quote

Yes, my logrotate config for syslog-ng is also default:
Code:

/var/log/messages {
    delaycompress
    missingok
    sharedscripts
    postrotate
        /etc/init.d/syslog-ng reload > /dev/null 2>&1 || true
    endscript
}


I also found something in the logs which might be part of the symptoms.
When the logrotate is successful the last lines of the rotated log file are:
Code:

May  1 03:09:02 lxc-mail start-stop-daemon[5119]: Will stop PID 822
May  1 03:09:02 lxc-mail start-stop-daemon[5119]: Sending signal 1 to PID 822

In the unsuccessful rotate the last line is only:
Code:

May  8 03:09:01 lxc-mail start-stop-daemon[6095]: Will stop PID 822

Where PID 822 was syslog-ng before i manually restarted it.

Maybe there is/was a bug in syslog-ng but which triggers when the HUP signal is send?
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
freke
l33t
l33t


Joined: 23 Jan 2003
Posts: 976
Location: Somewhere in Denmark

PostPosted: Mon May 09, 2022 7:22 am    Post subject: Reply with quote

pa4wdh wrote:
I also found something in the logs which might be part of the symptoms.
When the logrotate is successful the last lines of the rotated log file are:
Code:

May  1 03:09:02 lxc-mail start-stop-daemon[5119]: Will stop PID 822
May  1 03:09:02 lxc-mail start-stop-daemon[5119]: Sending signal 1 to PID 822

In the unsuccessful rotate the last line is only:
Code:

May  8 03:09:01 lxc-mail start-stop-daemon[6095]: Will stop PID 822

Where PID 822 was syslog-ng before i manually restarted it.

Maybe there is/was a bug in syslog-ng but which triggers when the HUP signal is send?

Actually I think logrotate/start-stop-daemon didn't send the signal to syslog-ng - wouldn't the 'Sending signal 1 to PID' be there if it did send the signal?
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Mon May 09, 2022 1:16 pm    Post subject: Reply with quote

The problem is that we don't know ...
It could be that start-stop-daemon indeed didn't send the signal
It could also be that start-stop-daemon did send the signal but the log message was not recorded because of the problem with syslog-ng

The log messages from syslog-ng which indicate the arrival of the signal are usually written to the next log file, which didn't happen because of the problem :(
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Tue May 10, 2022 8:53 am    Post subject: Reply with quote

I've been looking at the code for start-stop-daemon and syslog-ng to see if there is anything obvious i can find. I didn't find anything related to the problem i was seeing, but i did see something interesting in syslog-ng's code:
Right now when logrotate wants syslog-ng to re-open the log files it calls /etc/init.d/syslog-ng reload. The initscript sends the HUP signal to syslog-ng via start-stop-daemon.
The HUP signal triggers syslog-ng to re-read it's configuration files and re-open all output files. Judging from the amount of code involved this is a pretty complex process.
I found syslog-ng also triggers on the USR1 signal, and then it only re-opens all output files. This seems pretty straight-forward and easy.

Wouldn't it be better to let logrotate use the USR1 signal?
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Mon Jun 27, 2022 5:20 pm    Post subject: Reply with quote

Today this happened again. Since my last post in this topic there have been successful rotates June 5th, June 12th, June 19th (and probably earlier but those files are deleted) and it broke again yesterday.

I've now changed /etc/logrotate.d/syslog-ng to:
Code:

/var/log/messages {
    delaycompress
    missingok
    sharedscripts
    postrotate
       killall -USR1 syslog-ng
    endscript
}

To see if using USR1 fixes the problem.

Is anyone else seeing similar behavior?
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
gentoo_ram
Guru
Guru


Joined: 25 Oct 2007
Posts: 474
Location: San Diego, California USA

PostPosted: Tue Jun 28, 2022 12:27 am    Post subject: Reply with quote

Maybe something to do with the output of the init script? I see a couple other examples of getting syslog-ng to re-open files in my logrotate directory. Maybe try the other form by using '-q' as an argument to the script. I think that turns off logging.

Code:
gateway:/etc/logrotate.d$ grep syslog-ng *
dovecot:                /etc/init.d/syslog-ng -q reload
maillog:                /etc/init.d/syslog-ng -q reload
messages:        /etc/init.d/syslog-ng reload > /dev/null 2>&1 || true
smartd:         /etc/init.d/syslog-ng -q reload
Back to top
View user's profile Send private message
Goverp
Veteran
Veteran


Joined: 07 Mar 2007
Posts: 1998

PostPosted: Tue Jun 28, 2022 7:22 am    Post subject: Reply with quote

Mine works fine with the default /etc/logrotate.d/sylog-ng file. While digging, I note that /etc/logrotate.conf has a line
Code:
include /etc/logrotate.d
I wonder if that's gotten lost?
_________________
Greybeard
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Tue Jun 28, 2022 5:03 pm    Post subject: Reply with quote

Quote:
Maybe something to do with the output of the init script? I see a couple other examples of getting syslog-ng to re-open files in my logrotate directory. Maybe try the other form by using '-q' as an argument to the script. I think that turns off logging.

That's an interesting suggestion. One thing i've been thinking about is that this could be some kind of race condition because of the output (the syslog message which has to be processed on one hand, syslog-ng (which has to process that message) which is restarted on the other).

Quote:
I wonder if that's gotten lost?

The line is there, the rotation itself is done, it's just hat syslog-ng hangs afterwards which hangs every process that wants to send messages to syslog-ng.

Anyway, it might take a while before we know if the problem is solved now, as you can see from the time between my posts there is almost 1,5 month between the two occurrences of the problem ...
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
pa4wdh
l33t
l33t


Joined: 16 Dec 2005
Posts: 811

PostPosted: Sun Dec 18, 2022 12:23 pm    Post subject: Reply with quote

It has been almost half a year since the last time this happened, so i think it's quite save to say that my modification to the logrotate configuration solved the problem. 8)
_________________
The gentoo way of bringing peace to the world:
USE="-war" emerge --newuse @world

My shared code repository: https://code.pa4wdh.nl.eu.org
Music, Free as in Freedom: https://www.jamendo.com
Back to top
View user's profile Send private message
Display posts from previous:   
Reply to topic    Gentoo Forums Forum Index Networking & Security All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum