Clamd dying same time each day.

[mpl]

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

[falko]

I guess it is some cron job in /etc/cron.daily/.

[mpl]

Originally Posted by falko

I guess it is some cron job in /etc/cron.daily/.

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

[falko]

Can you post the output of

ls -la /etc/cron.daily/

?

[mpl]

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

[falko]

That looks ok. What's the output of

crontab -l

?

BTW, you could set up monit and make it restart clamd whenever it is not running.

[mpl]

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!

[mpl]

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

[falko]

Are there any errors in your mail log (in the /var/log/ directory)?

[mpl]

Hey Falco,
The truth is, I believe the issue with amavis and monit was due to some disk errors that have been solved now

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 ???

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