Good Day All, For the life of me I cannot figure out why clamav-daemon dies at the same time each day. After a simple "/etc/init.d/clamav-daemon start" we are good to go for another day. I think I have narrowed this down to some cron job but which one? Seems like the server.sh script is running at this time each day. Help please? Debian 10 Perfect Server ispconfig 3 Feb 6 06:28:27 webserver amavis[2134]: (02134-03) (!!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd.ctl (Can't connect to UNIX socket /var/run/clamav/clamd.ctl: Connection refused) at (eval 88) line 309. Feb 7 06:28:15 webserver amavis[2133]: (02133-06) (!!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd.ctl (Can't connect to UNIX socket /var/run/clamav/clamd.ctl: Connection refused) at (eval 88) line 309. Best Regards, Mike
Hello Falco ;-) Yep, that's what I am thinking... Here is something that just started today. I guess I need to figure this out before I can see where clamav is failing. Any ideas? Is it possible to step through the php script to figure out where this message is coming from? 1st. webserver:/etc/cron.daily# crontab -l * * * * * /usr/local/ispconfig/server/server.sh > /dev/null 2>> /var/log/ispconfig/cron.log 30 00 * * * /usr/local/ispconfig/server/cron_daily.sh > /dev/null 2>> /var/log/ispconfig/cron.log webserver:/etc/cron.daily# /usr/local/ispconfig/server/server.sh 2nd. webserver:/etc/cron.daily# /usr/local/ispconfig/server/server.sh finished. 3rd. webserver:/etc/cron.daily# /usr/local/ispconfig/server/cron_daily.sh Warning: Truncating oversized referrer field Warning: Truncating oversized referrer field Warning: Truncating oversized referrer field Warning: Truncating oversized referrer field Warning: Truncating oversized referrer field ////////////////////////////////////////////////////////////// So I check cron_daily.sh webserver:/home/www# cat /usr/local/ispconfig/server/cron_daily.sh #!/bin/sh PATH=/sbin:/usr/sbin:/bin:/usr/bin:/usr/local/sbin:/usr/local/bin:/usr/X11R6/bin /usr/bin/php -q /usr/local/ispconfig/server/cron_daily.php
Here you go! Thanks so much Falco ;-) webserver:/etc/postfix# ls -la /etc/cron.daily/ total 84 drwxr-xr-x 2 root root 4096 2011-01-22 13:26 . drwxr-xr-x 105 root root 4096 2011-02-09 16:18 .. -rwxr-xr-x 1 root root 199 2008-07-26 03:29 amavisd-new -rwxr-xr-x 1 root root 633 2010-12-11 13:59 apache2 -rwxr-xr-x 1 root root 7482 2010-05-12 16:25 apt -rwxr-xr-x 1 root root 314 2008-12-04 21:51 aptitude -rwxr-xr-x 1 root root 77 2008-09-16 04:28 apt-show-versions -rwxr-xr-x 1 root root 502 2007-11-20 02:35 bsdmainutils -rwxr-xr-x 1 root root 4073 2010-12-10 09:01 exim4-base -rwxr-xr-x 1 root root 89 2008-10-08 11:34 logrotate -rwxr-xr-x 1 root root 954 2009-01-24 07:31 man-db -rwxr-xr-x 1 root root 438 2008-10-28 06:18 mlocate -rwxr-xr-x 1 root root 1154 2009-11-22 12:35 ntp -rw-r--r-- 1 root root 102 2008-09-28 05:33 .placeholder -rwxr-xr-x 1 root root 345 2008-09-29 04:52 quota -rwxr-xr-x 1 root root 651 2008-08-25 13:03 rkhunter -rwxr-xr-x 1 root root 1142 2010-01-01 13:58 spamassassin -rwxr-xr-x 1 root root 330 2010-08-11 11:12 squirrelmail -rwxr-xr-x 1 root root 3349 2008-09-28 05:33 standard -rwxr-xr-x 1 root root 1450 2008-10-27 16:02 webalizer
That looks ok. What's the output of Code: crontab -l ? BTW, you could set up monit and make it restart clamd whenever it is not running.
Here you go Falco... webserver:/# crontab -l * * * * * /usr/local/ispconfig/server/server.sh > /dev/null 2>> /var/log/ispconfig/cron.log 30 00 * * * /usr/local/ispconfig/server/cron_daily.sh > /dev/null 2>> /var/log/ispconfig/cron.log and... webserver:/# monit status The monit daemon 4.10.1 uptime: 6m Process 'clamavd' status running monitoring status monitored pid 29329 parent pid 1 uptime 10h 15m childrens 0 memory kilobytes 96088 memory kilobytes total 96088 memory percent 37.4% memory percent total 37.4% cpu percent 0.0% cpu percent total 0.0% unix socket response time 0.002s to /var/run/clamav/clamd.ctl [DEFAULT] data collected Thu Feb 10 21:52:54 2011 System 'webserver.kd8q.com' status running monitoring status monitored load average [0.01] [0.04] [0.02] cpu 0.2%us 0.1%sy 0.2%wa memory usage 179852 kB [70.1%] data collected Thu Feb 10 21:52:54 2011 BTW...Thanks for suggesting Monit! Wonderful tool and just what I needed. I had actually started a script to restart clamav each day until I figured out why it was dying but Monit is a much better solution ;-) Many thanks Falco Oh and believe I figured out the "Warning: Truncating oversized referrer field" from earlier to be an error in Mysql caused by amavis-new and clamav both being dead. I think I will set up monit for amavis as well so I can hopefully catch when these two are actually choking!
What do you make of this???? webserver:/var/run/amavis# monit summary The monit daemon 4.10.1 uptime: 5m Process 'amavisd' not monitored File 'amavisd_bin' accessible File 'amavisd_rc' accessible Process 'apache' running Process 'clamd' running File 'clamavd_bin' accessible File 'clamavd_rc' accessible Process 'postfix' running File 'postfix_rc' accessible Process 'spamd' running File 'spamd_bin' accessible File 'spamd_rc' accessible Process 'syslogd' running File 'syslogd_file' accessible System 'webserver.kd8q.com' running webserver:/var/run/amavis# monit validate Sendmail error: 554 5.7.1 <*********@gmail.com>: Relay access denied Alert handler failed, retry scheduled for next cycle 'amavisd' process is not runningSendmail error: 554 5.7.1 <**********@gmail.com>: Relay access denied 'amavisd' trying to restart'amavisd' start: /etc/init.d/amavis Starting amavisd: 'amavisd' failed to startSendmail error: 554 5.7.1 <*********@gmail.com>: Relay access denied webserver:/var/run/amavis# amavisd-new. But then look at this..... webserver:/var/run/amavis# netstat -tap Active Internet connections (servers and established) Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name tcp 0 0 *:imaps *:* LISTEN 3187/dovecot tcp 0 0 *op3s *:* LISTEN 3187/dovecot tcp 0 0 *:53443 *:* LISTEN 2043/rpc.statd tcp 0 0 localhost:10024 *:* LISTEN 6469/amavisd (virgitcp 0 0 localhost:10025 *:* LISTEN 3141/master tcp 0 0 *:mysql *:* LISTEN 2374/mysqld tcp 0 0 *op3 *:* LISTEN 3187/dovecot tcp 0 0 *:imap2 *:* LISTEN 3187/dovecot tcp 0 0 localhost:spamd *:* LISTEN 2445/spamd.pid tcp 0 0 *:sunrpc *:* LISTEN 2032/portmap tcp 0 0 *:ftp *:* LISTEN 10528/pure-ftpd (SE tcp 0 0 webserver.kd8q.c:domain *:* LISTEN 2273/named tcp 0 0 localhost:domain *:* LISTEN 2273/named tcp 0 0 *:ssh *:* LISTEN 2287/sshd tcp 0 0 localhost:ipp *:* LISTEN 19914/cupsd tcp 0 0 *:smtp *:* LISTEN 3141/master tcp 0 0 localhost:953 *:* LISTEN 2273/named tcp 0 0 localhost:2812 *:* LISTEN 6461/monit tcp 0 0 localhost:mysql localhost:58702 ESTABLISHED 2374/mysqld tcp 0 0 webserver.kd8q.co:56376 cpe-184-57-205-235:smtp TIME_WAIT - tcp 50 0 localhost:42757 localhost:10025 CLOSE_WAIT 29417/amavisd (ch1- tcp 0 0 localhost:58686 localhost:mysql TIME_WAIT - tcp 0 0 localhost:smtp localhost:35268 TIME_WAIT - tcp 0 0 localhost:58702 localhost:mysql ESTABLISHED 6973/smtpd tcp 0 300 webserver.kd8q.com:ssh 63-253-225-1:supfiledbg ESTABLISHED 4686/sshd: www [pri tcp 0 0 localhost:mysql localhost:58685 TIME_WAIT - tcp 0 0 localhost:58704 localhost:mysql ESTABLISHED 6973/smtpd tcp 0 0 localhost:58684 localhost:mysql TIME_WAIT - tcp 0 0 localhost:58703 localhost:mysql ESTABLISHED 6973/smtpd tcp 0 0 localhost:mysql localhost:58703 ESTABLISHED 2374/mysqld tcp 0 0 localhost:mysql localhost:58704 ESTABLISHED 2374/mysqld tcp6 0 0 [::]:http-alt [::]:* LISTEN 305/apache2 tcp6 0 0 [::]:www [::]:* LISTEN 305/apache2 tcp6 0 0 [::]:tproxy [::]:* LISTEN 305/apache2 tcp6 0 0 [::]:ftp [::]:* LISTEN 10528/pure-ftpd (SE tcp6 0 0 [::]:domain [::]:* LISTEN 2273/named tcp6 0 0 [::]:ssh [::]:* LISTEN 2287/sshd tcp6 0 0 localhost:ipp [::]:* LISTEN 19914/cupsd tcp6 0 0 localhost:953 [::]:* LISTEN 2273/named tcp6 0 0 [::]:https [::]:* LISTEN 305/apache2 So amavis is running but monit thinks it is not and cannot send the email??? Strange
Hey Falco, The truth is, I believe the issue with amavis and monit was due to some disk errors that have been solved now Code: webserver:/var/log# monit summary The monit daemon 4.10.1 uptime: 9h 15m Process 'amavisd' running File 'amavisd_bin' accessible File 'amavisd_rc' accessible Process 'apache' running Process 'clamd' running File 'clamavd_bin' accessible File 'clamavd_rc' accessible Process 'postfix' running File 'postfix_rc' accessible Process 'spamd' running File 'spamd_bin' accessible File 'spamd_rc' accessible Process 'syslogd' running File 'syslogd_file' accessible System 'webserver.kd8q.com' running So that part is solved but... I still cannot figure out why clamav is dying ??? Code: Feb 12 01:20:32 webserver amavis[2275]: (02275-05) (!!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd.ctl (Can't connect to UNIX socket /var/run/clamav/clamd.ctl: Connection refused) at (eval 88) line 309. Feb 12 01:22:33 webserver amavis[2275]: (02275-06-6) (!!)TROUBLE in check_mail: virus_scan FAILED: virus_scan: ALL VIRUS SCANNERS FAILED: ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd.ctl (Can't connect to UNIX socket /var/run/clamav/clamd.ctl: Connection refused) at (eval 88) line 309.; ClamAV-clamscan av-scanner FAILED: run_av error: run_av: Exceeded allowed time at (eval 88) line 516. At least monit gets clamav restarted but I would sure like to get to the bottom of this. I have to believe something is happening with a cron job. This may sound like a silly question, but where do the "root" emails disappear too on an ispconfig3 system? I think the fact that I cannot find them and I noticed most times the mail queue contained a mail to root at almost the exact time clamav dies, that maybe this is related! Thank to all for your help
Is this a physical system or a virtual machine? Take a look at /etc/aliases. On most systems there is an alias for root that points to postmaster which means mails for root are forwarded to the user postmaster.
Hello Falco, This is a virtual machine. Here is my aliases file. webserver:/etc# cat aliases # /etc/aliases mailer-daemon: postmaster postmaster: root nobody: root hostmaster: root usenet: root news: root webmaster: root www: root ftp: root abuse: root noc: root security: root root: root clamav: root So I guess I still don't understand how to find the root mails. Also, here is something strange (to me anyway) that just showed up. I don't ever remember seeing any mails for getmail@ until yesterday? Thanks for all your help Falco....you have been very gracious ;-)
Here is a stalled email from the queue and a bit of the mail log as well! Data from: 2011-02-14 23:10 -Queue ID- --Size-- ----Arrival Time---- -Sender/Recipient------- 4559221C11A* 616 Mon Feb 14 23:10:01 [email protected] [email protected] -- 0 Kbytes in 1 Request. Feb 14 22:50:01 webserver postfix/pickup[9075]: 390CE21C11A: uid=5001 from= Feb 14 22:50:01 webserver postfix/cleanup[10913]: 390CE21C11A: message-id=<[email protected]> Feb 14 22:50:01 webserver postfix/qmgr[2952]: 390CE21C11A: from=, size=616, nrcpt=1 (queue active) Feb 14 22:50:02 webserver postfix/smtpd[10889]: connect from localhost[127.0.0.1] Feb 14 22:50:02 webserver postfix/smtpd[10889]: lost connection after CONNECT from localhost[127.0.0.1] Feb 14 22:50:02 webserver postfix/smtpd[10889]: disconnect from localhost[127.0.0.1] Feb 14 22:50:02 webserver dovecot: pop3-login: Disconnected: rip=127.0.0.1, lip=127.0.0.1, secured Feb 14 22:50:02 webserver dovecot: imap-login: Disconnected: rip=127.0.0.1, lip=127.0.0.1, secured Feb 14 22:50:02 webserver postfix/smtpd[10946]: connect from localhost[127.0.0.1] Feb 14 22:50:02 webserver postfix/smtpd[10946]: ADA5A21C119: client=localhost[127.0.0.1] Feb 14 22:50:02 webserver postfix/cleanup[10913]: ADA5A21C119: message-id=<[email protected]> Feb 14 22:50:02 webserver postfix/qmgr[2952]: ADA5A21C119: from=, size=1060, nrcpt=1 (queue active) Feb 14 22:50:02 webserver postfix/smtpd[10946]: disconnect from localhost[127.0.0.1] Feb 14 22:50:02 webserver amavis[7933]: (07933-19) Passed CLEAN, -> , Message-ID: <[email protected]>, mail_id: be5o4lYGS-gW, Hits: 2.829, size: 616, queued_as: ADA5A21C119, 1321 ms Feb 14 22:50:02 webserver postfix/smtp[10917]: 390CE21C11A: to=, orig_to=, relay=127.0.0.1[127.0.0.1]:10024, delay=1.7, delays=0.37/0.02/0.01/1.3, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=07933-19, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as ADA5A21C119) Feb 14 22:50:02 webserver postfix/qmgr[2952]: 390CE21C11A: removed Feb 14 22:50:02 webserver postfix/local[10947]: ADA5A21C119: to=, relay=local, delay=0.15, delays=0.06/0.05/0/0.05, dsn=2.0.0, status=sent (delivered to command: procmail -a "$EXTENSION") Feb 14 22:50:02 webserver postfix/qmgr[2952]: ADA5A21C119: removed Feb 14 22:50:24 webserver postfix/smtpd[10889]: connect from localhost[127.0.0.1] Feb 14 22:50:24 webserver postfix/smtpd[10889]: disconnect from localhost[127.0.0.1] Feb 14 22:52:24 webserver postfix/smtpd[10966]: connect from localhost[127.0.0.1] Feb 14 22:52:24 webserver postfix/smtpd[10966]: disconnect from localhost[127.0.0.1] Feb 14 22:54:24 webserver postfix/smtpd[10981]: connect from localhost[127.0.0.1] Feb 14 22:54:24 webserver postfix/smtpd[10981]: disconnect from localhost[127.0.0.1] Feb 14 22:55:01 webserver postfix/pickup[10951]: 5E02E21C11A: uid=5001 from= Feb 14 22:55:01 webserver postfix/cleanup[10994]: 5E02E21C11A: message-id=<[email protected]> Feb 14 22:55:01 webserver postfix/qmgr[2952]: 5E02E21C11A: from=, size=616, nrcpt=1 (queue active) Feb 14 22:55:02 webserver postfix/smtpd[10981]: connect from localhost[127.0.0.1] Feb 14 22:55:02 webserver postfix/smtpd[10981]: lost connection after CONNECT from localhost[127.0.0.1] Feb 14 22:55:02 webserver postfix/smtpd[10981]: disconnect from localhost[127.0.0.1] Feb 14 22:55:02 webserver dovecot: pop3-login: Disconnected: rip=127.0.0.1, lip=127.0.0.1, secured Feb 14 22:55:02 webserver dovecot: imap-login: Disconnected: rip=127.0.0.1, lip=127.0.0.1, secured Feb 14 22:55:07 webserver postfix/smtpd[11029]: connect from localhost[127.0.0.1] Feb 14 22:55:07 webserver postfix/smtpd[11029]: 112BF21C119: client=localhost[127.0.0.1] Feb 14 22:55:07 webserver postfix/cleanup[10994]: 112BF21C119: message-id=<[email protected]> Feb 14 22:55:07 webserver postfix/qmgr[2952]: 112BF21C119: from=, size=1060, nrcpt=1 (queue active) Feb 14 22:55:07 webserver amavis[10968]: (10968-01) Passed CLEAN, -> , Message-ID: <[email protected]>, mail_id: 1orlfAQSWHF5, Hits: 2.829, size: 616, queued_as: 112BF21C119, 5781 ms Feb 14 22:55:08 webserver postfix/smtp[10998]: 5E02E21C11A: to=, orig_to=, relay=127.0.0.1[127.0.0.1]:10024, delay=7.2, delays=0.18/0.02/1.7/5.4, dsn=2.0.0, status=sent (250 2.0.0 Ok, id=10968-01, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as 112BF21C119) Thanks Again!
Ok, there's no alias for root, so I guess mails for root ended up in the /var/spool/mail/ or /var/mail/ directory. You might want to create an alias like Code: root: [email protected] in /etc/aliases to have root emails forwarded to you. Please run Code: newaliases after you have modified /etc/aliases and restart Postfix.
