I have a very weird problem. Certain processes on my mail server, but not all, die periodically (every second month or so). A few of the process that die are:
- ssh
- dovecot
- postfix
Processes that don't die are:
- apache2
My system is running (Debian Wheezy):
$ uname -a
Linux hostname 3.2.0-4-amd64 #1 SMP Debian 3.2.41-2+deb7u2 x86_64 GNU/Linux
I have gone through /var/log
files, but they all seem to be quite after the incident, which always happens at 6:25 in the morning.
First I thought it had something with the ntpdate
daily cron to do, so I removed it and replaced it with ntpd
which doesn't need cron instead. Did it help? No.
Then I thought it had something with syslogd
to do. It seems that the processes who die are all trying to log using syslog. I googled around but I didn't find anyone else experiencing the same problem as me. It's really hard to find what the problem is when your logging mechanism doesn't work!
Here are all the log files that were modified around the incident time (6:25). There are no logs after that time, all logging activity ceased! Please take a look if you see something that might cause processes to die or logging to cease.
/var/log/syslog
Feb 16 06:25:01 hostname /USR/SBIN/CRON[32606]: (root) CMD (/usr/local/ispconfig/server/server.sh 2>&1 > /dev/null | while read line; do echo `/bin/date` "$line" >> /var/log/ispconfig/cron.log; done)
Feb 16 06:25:01 hostname /USR/SBIN/CRON[32607]: (getmail) CMD (/usr/local/bin/run-getmail.sh > /dev/null 2>> /dev/null)
Feb 16 06:25:01 hostname /USR/SBIN/CRON[32608]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
Feb 16 06:25:02 hostname dovecot: imap-login: Disconnected (disconnected before greeting, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<v9PKQn/y+gB/AAAB>
Feb 16 06:25:02 hostname postfix/smtpd[32647]: connect from localhost[127.0.0.1]
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [milter][end][connect][stop][0.000481](37362): milter-greylist
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [session][end][connect][accept][0.09962](37361)
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [sessions][finished] 18681(+1) 0
Feb 16 06:25:02 hostname postfix/smtpd[32647]: lost connection after CONNECT from localhost[127.0.0.1]
Feb 16 06:25:02 hostname postfix/smtpd[32647]: disconnect from localhost[127.0.0.1]
/var/log/php5-fpm.log
[09-Feb-2014 06:25:07] NOTICE: error log file re-opened
[16-Feb-2014 06:25:06] NOTICE: Terminating ...
[16-Feb-2014 06:25:07] NOTICE: exiting, bye-bye!
/var/log/mail.log
Feb 16 06:25:02 hostname dovecot: imap-login: Disconnected (disconnected before greeting, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<v9PKQn/y+gB/AAAB>
Feb 16 06:25:02 hostname postfix/smtpd[32647]: connect from localhost[127.0.0.1]
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [milter][end][connect][stop][0.000481](37362): milter-greylist
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [session][end][connect][accept][0.09962](37361)
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [sessions][finished] 18681(+1) 0
Feb 16 06:25:02 hostname postfix/smtpd[32647]: lost connection after CONNECT from localhost[127.0.0.1]
Feb 16 06:25:02 hostname postfix/smtpd[32647]: disconnect from localhost[127.0.0.1]
/var/log/mail.info
Feb 16 06:25:02 hostname dovecot: imap-login: Disconnected (disconnected before greeting, waited 0 secs): user=<>, rip=127.0.0.1, lip=127.0.0.1, secured, session=<v9PKQn/y+gB/AAAB>
Feb 16 06:25:02 hostname postfix/smtpd[32647]: connect from localhost[127.0.0.1]
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [milter][end][connect][stop][0.000481](37362): milter-greylist
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [session][end][connect][accept][0.09962](37361)
Feb 16 06:25:02 hostname milter-manager[2855]: [statistics] [sessions][finished] 18681(+1) 0
Feb 16 06:25:02 hostname postfix/smtpd[32647]: lost connection after CONNECT from localhost[127.0.0.1]
Feb 16 06:25:02 hostname postfix/smtpd[32647]: disconnect from localhost[127.0.0.1]
/var/log/fail2ban.log
2014-02-16 06:25:06,899 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:07,271 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/other_vhosts_access.log
2014-02-16 06:25:07,275 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:07,279 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:07,281 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:07,283 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/other_vhosts_access.log
2014-02-16 06:25:07,269 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/other_vhosts_access.log
2014-02-16 06:25:07,287 fail2ban.server : INFO Stopping all jails
2014-02-16 06:25:07,719 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:08,461 fail2ban.jail : INFO Jail 'php-url-fopen' stopped
2014-02-16 06:25:08,595 fail2ban.actions: WARNING [apache-w00tw00t] Unban 178.32.243.78
2014-02-16 06:25:08,702 fail2ban.actions: WARNING [apache-w00tw00t] Unban 83.212.122.172
2014-02-16 06:25:09,270 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:09,283 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:09,285 fail2ban.jail : INFO Jail 'apache-w00tw00t' stopped
2014-02-16 06:25:09,298 fail2ban.filter : INFO Log rotation detected for /var/log/apache2/error.log
2014-02-16 06:25:10,325 fail2ban.jail : INFO Jail 'apache-noscript' stopped
2014-02-16 06:25:11,361 fail2ban.jail : INFO Jail 'pam-generic' stopped
2014-02-16 06:25:12,330 fail2ban.jail : INFO Jail 'apache-badbots' stopped
2014-02-16 06:25:13,294 fail2ban.jail : INFO Jail 'apache-nohome' stopped
2014-02-16 06:25:14,326 fail2ban.jail : INFO Jail 'ssh-ddos' stopped
2014-02-16 06:25:14,827 fail2ban.jail : INFO Jail 'exim' stopped
2014-02-16 06:25:15,393 fail2ban.jail : INFO Jail 'webmin' stopped
2014-02-16 06:25:16,330 fail2ban.jail : INFO Jail 'apache' stopped
2014-02-16 06:25:17,296 fail2ban.jail : INFO Jail 'ssh' stopped
2014-02-16 06:25:18,285 fail2ban.jail : INFO Jail 'apache-overflows' stopped
2014-02-16 06:25:18,504 fail2ban.jail : INFO Jail 'dovecot' stopped
2014-02-16 06:25:19,333 fail2ban.jail : INFO Jail 'squirrelmail' stopped
2014-02-16 06:25:20,335 fail2ban.jail : INFO Jail 'apache-myadmin' stopped
2014-02-16 06:25:20,336 fail2ban.server : INFO Exiting Fail2ban
/var/log/auth.log
Feb 16 06:25:01 hostname CRON[32604]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 16 06:25:01 hostname CRON[32605]: pam_unix(cron:session): session opened for user getmail by (uid=0)
Feb 16 06:25:01 hostname CRON[32603]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 16 06:25:01 hostname CRON[32605]: pam_unix(cron:session): session closed for user getmail
Feb 16 06:25:02 hostname CRON[32604]: pam_unix(cron:session): session closed for user root