Topic: amavis crashing during update?
==== Required information ====
- iRedMail version: 0.8.7
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MYSQL
- Linux/BSD distribution name and version: Centos 6.6 x86_64
====
looks like amavis dies when freshclam runs: happens every night
messages:
Dec 24 03:45:45 post puppet-agent[12273]: Finished catalog run in 9.68 seconds
Dec 24 03:50:05 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 03:50:46 post puppet-agent[13360]: Finished catalog run in 10.18 seconds
Dec 24 03:55:45 post puppet-agent[14444]: Finished catalog run in 9.19 seconds
Dec 24 04:00:48 post puppet-agent[15547]: Finished catalog run in 12.15 seconds
Dec 24 04:01:13 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 04:04:54 post freshclam[16745]: ClamAV update process started at Wed Dec 24 04:04:54 2014
Dec 24 04:04:54 post freshclam[16745]: main.cvd is up to date (version: 55, sigs: 2424225, f-level: 60, builder: neo)
Dec 24 04:05:26 post freshclam[16745]: nonblock_recv: recv timing out (30 secs)
Dec 24 04:05:26 post freshclam[16745]: getfile: Error while reading database from db.us.clamav.net (IP: 104.131.196.175): Operation now in progress
Dec 24 04:05:26 post freshclam[16745]: getpatch: Can't download daily-19827.cdiff from db.us.clamav.net
Dec 24 04:05:45 post puppet-agent[16746]: Finished catalog run in 9.40 seconds
Dec 24 04:05:57 post freshclam[16745]: nonblock_connect: connect timing out (30 secs)
Dec 24 04:05:57 post freshclam[16745]: Can't connect to port 80 of host db.us.clamav.net (IP: 65.19.179.67)
Dec 24 04:05:57 post freshclam[16745]: Trying host db.us.clamav.net (64.6.100.177)...
Dec 24 04:05:57 post freshclam[16745]: Downloading daily-19827.cdiff [100%]
Dec 24 04:05:57 post freshclam[16745]: Downloading daily-19828.cdiff [100%]
Dec 24 04:05:58 post freshclam[16745]: Downloading daily-19829.cdiff [100%]
Dec 24 04:05:58 post freshclam[16745]: Downloading daily-19830.cdiff [100%]
Dec 24 04:05:58 post freshclam[16745]: Downloading daily-19831.cdiff [100%]
Dec 24 04:05:58 post freshclam[16745]: Downloading daily-19832.cdiff [100%]
Dec 24 04:06:06 post freshclam[16745]: daily.cld updated (version: 19832, sigs: 1296333, f-level: 63, builder: neo)
Dec 24 04:06:07 post freshclam[16745]: bytecode.cvd is up to date (version: 244, sigs: 44, f-level: 63, builder: dgoddard)
Dec 24 04:06:10 post freshclam[16745]: Database updated (3720602 signatures) from db.us.clamav.net (IP: 64.6.100.177)
Dec 24 04:10:49 post puppet-agent[18023]: Finished catalog run in 12.83 seconds
Dec 24 04:11:13 post clamd[1114]: SelfCheck: Database modification detected. Forcing reload.
Dec 24 04:11:30 post clamd[1114]: Reading databases from /var/lib/clamav
Dec 24 04:11:38 post clamd[1114]: Database correctly reloaded (3715045 signatures)
Dec 24 04:15:47 post puppet-agent[19114]: Finished catalog run in 9.90 seconds
Dec 24 04:20:46 post puppet-agent[20207]: Finished catalog run in 10.93 seconds
Dec 24 04:21:38 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 04:25:45 post puppet-agent[21319]: Finished catalog run in 9.75 seconds
Dec 24 04:30:45 post puppet-agent[22408]: Finished catalog run in 8.83 seconds
Dec 24 04:31:38 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 04:35:47 post puppet-agent[23493]: Finished catalog run in 11.66 seconds
Dec 24 04:40:47 post puppet-agent[24581]: Finished catalog run in 11.29 seconds
Dec 24 04:41:38 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 04:45:44 post puppet-agent[25665]: Finished catalog run in 8.63 seconds
Dec 24 04:50:45 post puppet-agent[26754]: Finished catalog run in 9.47 seconds
Dec 24 04:51:39 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 04:55:44 post puppet-agent[27838]: Finished catalog run in 8.30 seconds
Dec 24 05:00:44 post puppet-agent[28927]: Finished catalog run in 8.11 seconds
Dec 24 05:01:39 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 05:05:44 post puppet-agent[30029]: Finished catalog run in 8.08 seconds
Dec 24 05:10:44 post puppet-agent[31120]: Finished catalog run in 8.18 seconds
Dec 24 05:11:39 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 05:15:44 post puppet-agent[32204]: Finished catalog run in 8.08 seconds
Dec 24 05:20:44 post puppet-agent[836]: Finished catalog run in 7.94 seconds
Dec 24 05:21:39 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 05:25:44 post puppet-agent[1985]: Finished catalog run in 8.04 seconds
Dec 24 05:30:43 post puppet-agent[3073]: Finished catalog run in 7.42 seconds
Dec 24 05:31:39 post clamd[1114]: SelfCheck: Database status OK.
Dec 24 05:35:41 post puppet-agent[4220]: (/Stage[main]/Mta/Service[amavisd]/ensure) ensure changed 'stopped' to 'running'
Dec 24 05:35:45 post puppet-agent[4220]: Finished catalog run in 8.89 seconds
Dec 24 05:40:41 post puppet-agent[5324]: (/Stage[main]/Mta/Service[amavisd]/ensure) ensure changed 'stopped' to 'running'
Dec 24 05:40:45 post puppet-agent[5324]: Finished catalog run in 9.41 seconds
Dec 24 05:41:39 post clamd[1114]: SelfCheck: Database status OK.
maillog:
Dec 24 05:32:03 post postfix/smtpd[3823]: connect from unknown[10.0.0.9]
Dec 24 05:32:04 post postfix/smtpd[3823]: A7FF434190A: client=unknown[10.0.0.9]
Dec 24 05:32:04 post postfix/cleanup[3827]: A7FF434190A: message-id=<>
Dec 24 05:32:05 post postfix/smtpd[3823]: disconnect from unknown[10.0.0.9]
Dec 24 05:32:05 post postfix/qmgr[1428]: A7FF434190A: from=<checkmkomd@natetron.net>, size=5802, nrcpt=1 (queue active)
Dec 24 05:32:06 post postfix/smtp[3832]: connect to 127.0.0.1[127.0.0.1]:10024: Connection refused
Dec 24 05:32:07 post postfix/smtp[3832]: A7FF434190A: to=<DATAMASKEDt>, relay=none, delay=2.8, delays=1.5/1.3/0/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:10024: Connection refused)
Dec 24 05:32:20 post amavis[3839]: starting. /usr/sbin/amavisd at post.natetron.net amavisd-new-2.9.1 (20140627), Unicode aware, LANG="en_US.UTF-8"
Dec 24 05:32:21 post amavis[3840]: (!)Net::Server: 2014/12/24-05:32:21 Can't connect to TCP port 10024 on ::1 [Cannot assign requested address]\n at line 68 in file /usr/share/perl5/vendor_perl/Net/Server/Proto/TCP.pm
here's the state of things when I try to restart the services:
Shutting down amavisd: The amavisd daemon is apparently not running, no PID file /var/run/amavisd/amavisd.pid
[FAILED]
Starting amavisd: [ OK ]
Stopping Clam AntiVirus Daemon: [ OK ]
Starting Clam AntiVirus Daemon: [ OK ]
Stopping clamd.amavisd: [FAILED]
Starting clamd.amavisd: [ OK ]
Stopping Dovecot Imap: [ OK ]
Starting Dovecot Imap: [ OK ]
Stopping mysqld: [ OK ]
Starting mysqld: [ OK ]
Shutting down cbpolicyd: [ OK ]
Starting cbpolicyd: [ OK ]
Stopping iredapd ...
Starting iredapd ...
Shutting down postfix: [ OK ]
Starting postfix: [ OK ]
Stopping saslauthd: [FAILED]
Starting saslauthd: [ OK ]
Stopping spamd: [FAILED]
Starting spamd: [ OK ]
I can get everything back up but amavisd:
# service amavisd status
amavisd dead but subsys locked
I think this is the real error:
maillog:Dec 24 06:20:40 post amavis[14514]: (!)Net::Server: 2014/12/24-06:20:40 Can't connect to TCP port 10024 on ::1 [Cannot assign requested address]\n at line 68 in file /usr/share/perl5/vendor_perl/Net/Server/Proto/TCP.pm
# amavisd debug
Config file "/etc/amavisd.conf" does not exist, at /usr/sbin/amavisd line 2148.
----
Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.