AS/AV crash on Zimbra 7

[armitage318]

Hi,

I'm using zcs-7.1.0_GA_3140.RHEL5_64.20110329150833 on a CentOS VPS.
Often mail server stops working, and in Zimbra Admin Interface I see amavisd stopped.
This is my zimbra.log:

Jun 7 09:22:40 zimbra-server slapd[30967]: slap_queue_csn: queing 0x44f43540 20110607072240.257338Z#000000#000#000000
Jun 7 09:22:40 zimbra-server slapd[30967]: slap_graduate_commit_csn: removing 0x188d38a0 20110607072240.257338Z#000000#000#000000
Jun 7 09:23:22 zimbra-server amavis[32540]: Net::Server: 2011/06/07-09:23:22 Server closing!
Jun 7 09:23:28 zimbra-server amavis[9537]: starting. /opt/zimbra/amavisd/sbin/amavisd at zimbra-server.organization.it amavisd-new-2.6.4 (20090625), Unicode aware, LC_ALL="C", LANG="C"
Jun 7 09:23:28 zimbra-server amavis[9537]: user=500, EUID: 500 (500); group=, EGID: 500 501 500 5 4 (500 501 500 5 4)
Jun 7 09:23:28 zimbra-server amavis[9537]: Perl version 5.008008
Jun 7 09:23:29 zimbra-server amavis[9537]: SpamControl: init_pre_chroot on SpamAssassin done
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: Process Backgrounded
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: 2011/06/07-09:23:29 Amavis (type Net::Server::PreForkSimple) starting! pid(9541)
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: Using default listen value of 128
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: Binding to UNIX socket file /opt/zimbra/data/amavisd/amavisd.sock using SOCK_STREAM
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: Group Not Defined. Defaulting to EGID '500 501 500 5 4'
Jun 7 09:23:29 zimbra-server amavis[9541]: Net::Server: User Not Defined. Defaulting to EUID '500'
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Amavis::Conf 2.207
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Archive::Zip 1.30
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Compress::Zlib 1.42
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Convert::TNEF 0.17
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Convert::UUlib 1.34
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Crypt::OpenSSL::RSA 0.26
Jun 7 09:23:29 zimbra-server amavis[9541]: Module DBD::mysql 4.018
Jun 7 09:23:29 zimbra-server amavis[9541]: Module DBI 1.616
Jun 7 09:23:29 zimbra-server amavis[9541]: Module DB_File 1.821
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Digest::MD5 2.36
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Digest::SHA 5.50
Jun 7 09:23:29 zimbra-server amavis[9541]: Module IO::Socket::INET6 2.67
Jun 7 09:23:29 zimbra-server amavis[9541]: Module MIME::Entity 5.427
Jun 7 09:23:29 zimbra-server amavis[9541]: Module MIME::Parser 5.427
Jun 7 09:23:29 zimbra-server amavis[9541]: Module MIME::Tools 5.427
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail:KIM::Signer 0.39
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail:KIM::Verifier 0.39
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail::Header 2.07
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail::Internet 2.07
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail::SPF 2.008
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Mail::SpamAssassin 3.003001
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Net:NS 0.66
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Net::LDAP 0.4001
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Net::Server 0.99
Jun 7 09:23:29 zimbra-server amavis[9541]: Module NetAddr::IP 4.040
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Socket6 0.23
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Time::HiRes 1.9721
Jun 7 09:23:29 zimbra-server amavis[9541]: Module URI 1.58
Jun 7 09:23:29 zimbra-server amavis[9541]: Module Unix::Syslog 1.1
Jun 7 09:23:29 zimbra-server amavis[9541]: Amavis:B code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Amavis::Cache code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: SQL base code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: SQL::Log code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: SQL::Quarantine NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Lookup::SQL code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Lookup::LDAP code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: AM.PDP-in proto code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: SMTP-in proto code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Courier proto code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: SMTP-out proto code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Pipe-out proto code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: BSMTP-out proto code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Local-out proto code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: OS_Fingerprint code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: ANTI-VIRUS code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: ANTI-SPAM code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: ANTI-SPAM-EXT code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: ANTI-SPAM-C code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: ANTI-SPAM-SA code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Unpackers code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: DKIM code loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Tools code NOT loaded
Jun 7 09:23:29 zimbra-server amavis[9541]: Found $file at /usr/bin/file
Jun 7 09:23:29 zimbra-server amavis[9541]: No $altermime, not using it
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .mail
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .asc
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .uue
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .hqx
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .ync
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .F tried: unfreeze, freeze -d, melt, fcat
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .Z at /usr/bin/gzip -d
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .gz at /usr/bin/gzip -d
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .bz2 at /usr/bin/bzip2 -d
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .lzo tried: lzop -d
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .rpm at /usr/bin/rpm2cpio
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .cpio at /usr/bin/pax
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .tar at /usr/bin/pax
Jun 7 09:23:29 zimbra-server amavis[9541]: Found decoder for .deb at /usr/bin/ar
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .zip
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .7z tried: 7zr, 7za, 7z
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .rar tried: rar, unrar
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .arj tried: arj, unarj
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .arc tried: nomarch, arc
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .zoo tried: zoo, unzoo
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .lha tried: lha
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .cab tried: cabextract
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .tnef tried: tnef
Jun 7 09:23:29 zimbra-server amavis[9541]: Internal decoder for .tnef
Jun 7 09:23:29 zimbra-server amavis[9541]: No decoder for .exe tried: rar, unrar; lha; arj, unarj
Jun 7 09:23:29 zimbra-server amavis[9541]: Using primary internal av scanner code for ClamAV-clamd
Jun 7 09:23:29 zimbra-server amavis[9541]: initializing Mail::SpamAssassin
Jun 7 09:23:30 zimbra-server amavis[9541]: SpamControl: init_pre_fork on SpamAssassin done
Jun 7 09:23:30 zimbra-server amavis[9541]: extra modules loaded after daemonizing/chrooting: Mail/SpamAssassin/Plugin/FreeMail.pm
Jun 7 09:23:31 zimbra-server postfix/smtpd[27565]: connect from dude.lan.organization.com[195.32.84.23]
Jun 7 09:23:31 zimbra-server postfix/smtpd[27565]: lost connection after EHLO from dude.lan.organization.com[195.32.84.23]
Jun 7 09:23:31 zimbra-server postfix/smtpd[27565]: disconnect from dude.lan.organization.com[195.32.84.23]
Jun 7 09:23:46 zimbra-server clamd[32712]: Pid file removed.
Jun 7 09:23:46 zimbra-server clamd[32712]: --- Stopped at Tue Jun 7 09:23:46 2011
Jun 7 09:23:49 zimbra-server clamd[9645]: clamd daemon 0.97-broken-compiler (OS: linux-gnu, ARCH: x86_64, CPU: x86_64)
Jun 7 09:23:49 zimbra-server clamd[9645]: Log file size limited to 20971520 bytes.
Jun 7 09:23:49 zimbra-server clamd[9645]: Reading databases from /opt/zimbra/data/clamav/db
Jun 7 09:23:49 zimbra-server clamd[9645]: Not loading PUA signatures.
Jun 7 09:23:55 zimbra-server clamd[9645]: Loaded 970857 signatures.
Jun 7 09:23:56 zimbra-server clamd[9645]: TCP: Bound to address 127.0.0.1 on port 3310
Jun 7 09:23:56 zimbra-server clamd[9645]: TCP: Setting connection queue length to 200
Jun 7 09:23:56 zimbra-server clamd[9649]: Limits: Global size limit set to 2000000000 bytes.
Jun 7 09:23:56 zimbra-server clamd[9649]: Limits: File size limit set to 2000000000 bytes.
Jun 7 09:23:56 zimbra-server clamd[9649]: Limits: Recursion level limit set to 16.
Jun 7 09:23:56 zimbra-server clamd[9649]: Limits: Files limit set to 10000.
Jun 7 09:23:56 zimbra-server clamd[9649]: Archive support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: Archive: Blocking encrypted archives.
Jun 7 09:23:56 zimbra-server clamd[9649]: Algorithmic detection enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: Portable Executable support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: ELF support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: Mail files support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: OLE2 support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: PDF support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: HTML support enabled.
Jun 7 09:23:56 zimbra-server clamd[9649]: Self checking every 600 seconds.
Jun 7 09:24:01 zimbra-server postfix/smtpd[24333]: connect from dude.lan.organization.com[195.32.84.23]
Jun 7 09:24:01 zimbra-server postfix/smtpd[24333]: lost connection after EHLO from dude.lan.organization.com[195.32.84.23]
Jun 7 09:24:01 zimbra-server postfix/smtpd[24333]: disconnect from dude.lan.organization.com[195.32.84.23]
Jun 7 09:24:05 zimbra-server zmmailboxdmgr[9973]: status requested
Jun 7 09:24:05 zimbra-server zmmailboxdmgr[9973]: status OK
Jun 7 09:24:16 zimbra-server amavis[9541]: Net::Server: 2011/06/07-09:24:16 Server closing!
Jun 7 09:24:17 zimbra-server clamd[9649]: Reading databases from /opt/zimbra/data/clamav/db

Anyone can help me on this issue?
Thankyou

[sem]

Hi. Check the MTA Trusted Networks values for Global and server settings. I kept having AV/AS stop - in Global settings, the trusted networks are listed on one line, separated by a space. On the server MTA tab, they are separated by a line break - this breaks salocal.cf on my install (zcs-7.1.1_GA_3196.UBUNTU10_64.20110527011124). The setting in Server MTA tab won't allow networks to be specified on a single line.

I modified salocal.cf to put the two networks on one line, restarted amavisd and haven't had a problem all day. Unless I edit the server settings in the backend - in which case, the line break config returns. Have posted as a bug:

https://bugzilla.zimbra.com/show_bug.cgi?id=60590

[armitage318]

Ok! Thankyou very much!