Centos6, new server, unable to start amavisd

Discussion in 'Server Operation' started by Scott Horton, Jul 17, 2016.

  1. Scott Horton

    Scott Horton New Member

    (Have to post in pieces to get my post count up so I can post the meat of it which has some text being flagged as links)

    I'm trying to spin up a new server to replace an aging dedicated one. I've used my configs, carefully editing the new .conf files to be sure I didn't miss any new settings from newer versions. I have the box named with a fqdn,


    ....
     
  2. Scott Horton

    Scott Horton New Member

    I can start postfix without obvious error:

    Jul 17 09:26:55 tn3 postfix/master[1061]: terminating on signal 15
    Jul 17 09:26:55 tn3 postfix/postfix-script[10899]: starting the Postfix mail system
    Jul 17 09:26:55 tn3 postfix/master[10901]: daemon started -- version 2.10.1, configuration /etc/postfix

    I can apparently start amavisd outside of systemctl
    This runs without error:
    /usr/sbin/amavisd -c /etc/amavisd/amavisd.conf

    # ps ax|grep amav

    10495 ? Ss 0:00 /bin/bash /usr/share/clamav/freshclam-sleep
    11004 ? Ss 0:01 /usr/sbin/amavisd (master)
    11005 ? S 0:00 /usr/sbin/amavisd (virgin child)
    11006 ? S 0:00 /usr/sbin/amavisd (virgin child)
    11007 ? S 0:00 /usr/sbin/amavisd (virgin child)


     
    Last edited: Jul 17, 2016
  3. Scott Horton

    Scott Horton New Member

    After executing above the tail end of the maillog shows;
    Jul 17 09:33:01 tn3 amavis[10962]: Found decoder for .iso at /usr/bin/7z
    Jul 17 09:33:01 tn3 amavis[10962]: Found decoder for .exe at /usr/bin/unarj
    Jul 17 09:33:01 tn3 amavis[10962]: No decoder for .lz4
    Jul 17 09:33:01 tn3 amavis[10962]: Using primary internal av scanner code for ClamAV-clamd
    Jul 17 09:33:01 tn3 amavis[10962]: Found secondary av scanner ClamAV-clamscan at /usr/bin/clamscan
    Jul 17 09:33:01 tn3 amavis[10962]: Deleting db files snmp.db,__db.003,__db.002,nanny.db,__db.001 in /home/amavis/db
    Jul 17 09:33:01 tn3 amavis[10962]: Creating db in /home/amavis/db/; BerkeleyDB 0.51, libdb 5.3
    Jul 17 09:33:01 tn3 amavis[10962]: initializing Mail::SpamAssassin (0)
    Jul 17 09:33:02 tn3 amavis[10962]: SpamControl: init_pre_fork on SpamAssassin done
    Jul 17 09:33:02 tn3 amavis[10962]: extra modules loaded after daemonizing/chrooting: /usr/share/perl5/Net/libnet.cfg, Mail/SpamAssassin/Plugin/FreeMail.pm, Mail/SpamAssassin/Plugin/SpamCop.pm, Net/Cmd.pm, Net/Config.pm, Net/SMTP.pm​

    But if I try to start via systemctl, it fails:
    Job for amavisd.service failed because the control process exited with error code. See "systemctl status amavisd.service" and "journalctl -xe" for details.
     
  4. Scott Horton

    Scott Horton New Member

    [root@tn3 ~]# systemctl status amavisd.service
    * amavisd.service - Amavisd-new is an interface between MTA and content checkers.
    Loaded: loaded (/usr/lib/systemd/system/amavisd.service; enabled; vendor preset: disabled)
    Active: failed (Result: start-limit) since Sun 2016-07-17 09:34:56 CDT; 54s ago
    Docs: http://www.ijs.si/software/amavisd/#doc
    Process: 10990 ExecStart=/usr/sbin/amavisd -c /etc/amavisd/amavisd.conf (code=exited, status=13)

    Jul 17 09:34:55 tn3.myserver.com systemd[1]: amavisd.service: control process exited, code=exited status=13
    Jul 17 09:34:55 tn3.myserver.com systemd[1]: Failed to start Amavisd-new is an interface between MTA and content checkers..
    Jul 17 09:34:55 tn3.myserver.com systemd[1]: Unit amavisd.service entered failed state.
    Jul 17 09:34:55 tn3.myserver.com systemd[1]: amavisd.service failed.
    Jul 17 09:34:56 tn3.myserver.com systemd[1]: amavisd.service holdoff time over, scheduling restart.
    Jul 17 09:34:56 tn3.myserver.com systemd[1]: start request repeated too quickly for amavisd.service
    Jul 17 09:34:56 tn3.myserver.com systemd[1]: Failed to start Amavisd-new is an interface between MTA and content checkers..
    Jul 17 09:34:56 tn3.myserver.com systemd[1]: Unit amavisd.service entered failed state.
    Jul 17 09:34:56 tn3.myserver.com systemd[1]: amavisd.service failed.​

    I looked here, and from googling changed the one option to false, but it didn't help.
    /etc/systemd/system/multi-user.target.wants/amavisd.service
    [Unit]
    Description=Amavisd-new is an interface between MTA and content checkers.
    Documentation=http://www.ijs.si/software/amavisd/#doc
    After=network.target
    Wants=[email protected]
    Wants=postfix.service

    [Service]
    Type=forking
    User=amavis
    Group=amavis
    PIDFile=/var/run/amavisd/amavisd.pid
    ExecStart=/usr/sbin/amavisd -c /etc/amavisd/amavisd.conf
    ExecReload=/usr/sbin/amavisd -c /etc/amavisd/amavisd.conf reload
    Restart=on-failure
    PrivateTmp=true
    NoNewPrivileges=false

    [Install]
    WantedBy=multi-user.target​

    I'm checked and fiddled with permissions making them mirror the functional server, didn't help. I've deleted and recreated the db files, the PID file, still no good. I've verified fqdn, made sure reverse DNS is set, everything I can think of.

    I've exhausted my ability to fix it. Can someone help me troubleshoot it please? :(
     
  5. Thaddeus

    Thaddeus New Member

    try chmod 644 /etc/amavisd/amavisd.conf
     
  6. Scott Horton

    Scott Horton New Member

    chmod made no difference. Almost positive I tried that, but did again anyway.

    Starting to suspect clamav is not installed or working right. Could tha tcause it? Did I mention I hate the systemctl thing LOL. I don't know how to "unhook" clamav from amavisd for testing.
     
  7. Thaddeus

    Thaddeus New Member

    Do both /etc/amavisd.conf and /etc/amavisd/amavisd.conf exist? Check what clam packages are installed. yum list installed | grep clam
     
  8. Scott Horton

    Scott Horton New Member

    only this one: /etc/amavisd/amavisd.conf

    For clamav, I just uninstalled all packages via yum then deleted all the leftover config files with the names clamav, clamd, or freshclam. As clean a start a I know how to get it. About to try again.

    Found several tutorials, I've been looking at the ones for Centos 7 as they seem to be the only ones that address the new systemctl stuff. I gather there are different clamav/clamd packages out there and maybe I got the crossed up trying to fix.

    Some guides use stock packages, some have you do this first;
    yum install epel-release
    Different guides have you get different yum packages, some reference files that don't get installed, etc. Mixed up.

    I was about to try this guide to see how it goes...He seemed to run into install issues. Going to lunch first. Head hurts :). Open to better suggestions

    https://www.adminsys.ch/2015/08/21/installing-clamav-epel-centosred-hat-7-nightmare/
     
  9. Scott Horton

    Scott Horton New Member

    Where do I disable clamav in amavisd so I can see if that's the issue. Looks like clamav is a cluster to get working. Prefer to fix Amavisd first.
     
  10. Scott Horton

    Scott Horton New Member

    I removed and reinstalled amavisd with EPEL loaded. In case there wa s abetter package it would find. I found that if I run it as "amavisd debug" is was lookign for the config file in /etc. So I linked the one in /etc/amavisd there. then it would start in debug mode.

    I figured out where to turn off clamav to take that out of the picture. So I did that and tried to start amavisd via systemctl. Still get the errors.
    So I started manually with
    /usr/sbin/amavisd -c /etc/amavisd/amavisd.conf
    Appears to work fine. An internal mail processes with this running manually.

    When I execute above maillog shows:
    Jul 17 16:39:44 tn3 amavis[2560]: starting. /usr/sbin/amavisd at tn3.myserver.com amavisd-new-2.10.1 (20141025), Unicode aware, LANG="en_US"
    Jul 17 16:39:44 tn3 amavis[2560]: perl=5.016003, user=, EUID: 995 (995); group=, EGID: 992 992 (992 992)
    Jul 17 16:39:48 tn3 amavis[2560]: SpamControl: init_pre_chroot on SpamAssassin done
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: Process Backgrounded
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: 2016/07/17-16:39:48 Amavis (type Net::Server::preForkSimple) starting! pid(2562)
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: Binding to TCP port 10024 on host ::1 with IPv6
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: Group Not Defined. Defaulting to EGID '992 992'
    Jul 17 16:39:48 tn3 amavis[2562]: Net::Server: User Not Defined. Defaulting to EUID '995'
    Jul 17 16:39:48 tn3 amavis[2562]: Module Amavis::Conf 2.404
    Jul 17 16:39:48 tn3 amavis[2562]: Module Archive::Zip 1.30
    Jul 17 16:39:48 tn3 amavis[2562]: Module BerkeleyDB 0.51
    Jul 17 16:39:48 tn3 amavis[2562]: Module Compress::Raw::Zlib 2.061
    Jul 17 16:39:48 tn3 amavis[2562]: Module Compress::Zlib 2.061
    Jul 17 16:39:48 tn3 amavis[2562]: Module Crypt::OpenSSL::RSA 0.28
    Jul 17 16:39:48 tn3 amavis[2562]: Module DB_File 1.83
    Jul 17 16:39:48 tn3 amavis[2562]: Module Digest::MD5 2.52
    Jul 17 16:39:48 tn3 amavis[2562]: Module Digest::SHA 5.85
    Jul 17 16:39:48 tn3 amavis[2562]: Module Encode 2.51
    Jul 17 16:39:48 tn3 amavis[2562]: Module File::Temp 0.2301
    Jul 17 16:39:48 tn3 amavis[2562]: Module IO::Socket::INET6 2.69
    Jul 17 16:39:48 tn3 amavis[2562]: Module IO::Socket::IP 0.21
    Jul 17 16:39:48 tn3 amavis[2562]: Module MIME::Entity 5.505
    Jul 17 16:39:48 tn3 amavis[2562]: Module MIME::parser 5.505
    Jul 17 16:39:48 tn3 amavis[2562]: Module MIME::Tools 5.505
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::DKIM::Signer 0.39
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::DKIM::Verifier 0.39
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::Header 2.12
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::Internet 2.12
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::SPF v2.008
    Jul 17 16:39:48 tn3 amavis[2562]: Module Mail::SpamAssassin 3.004000
    Jul 17 16:39:48 tn3 amavis[2562]: Module Net::DNS 0.72
    Jul 17 16:39:48 tn3 amavis[2562]: Module Net::LibIDN 0.12
    Jul 17 16:39:48 tn3 amavis[2562]: Module Net::Server 2.007
    Jul 17 16:39:48 tn3 amavis[2562]: Module NetAddr::IP 4.069
    Jul 17 16:39:48 tn3 amavis[2562]: Module Razor2::Client::Version 2.84
    Jul 17 16:39:48 tn3 amavis[2562]: Module Scalar::Util 1.27
    Jul 17 16:39:48 tn3 amavis[2562]: Module Socket 2.010
    Jul 17 16:39:48 tn3 amavis[2562]: Module Socket6 0.23
    Jul 17 16:39:48 tn3 amavis[2562]: Module Time::HiRes 1.9725
    Jul 17 16:39:48 tn3 amavis[2562]: Module URI 1.60
    Jul 17 16:39:48 tn3 amavis[2562]: Module Unix::Syslog 1.1
    Jul 17 16:39:48 tn3 amavis[2562]: Amavis::ZMQ code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Amavis::DB code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: SQL base code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: SQL::Log code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: SQL::Quarantine NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Lookup::SQL code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Lookup::LDAP code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: AM.PDP-in proto code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: SMTP-in proto code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Courier proto code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: SMTP-out proto code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Pipe-out proto code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: BSMTP-out proto code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Local-out proto code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: OS_Fingerprint code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: ANTI-VIRUS code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: ANTI-SPAM code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: ANTI-SPAM-EXT code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: ANTI-SPAM-C code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: ANTI-SPAM-SA code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Unpackers code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: DKIM code loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Tools code NOT loaded
    Jul 17 16:39:48 tn3 amavis[2562]: Found $file at /usr/bin/file
    Jul 17 16:39:48 tn3 amavis[2562]: Found $altermime at /usr/bin/altermime
    Jul 17 16:39:48 tn3 amavis[2562]: Internal decoder for .mail
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .F at /usr/bin/unfreeze
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .Z at /usr/bin/gzip -d
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .gz at /usr/bin/gzip -d
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .bz2 at /usr/bin/bzip2 -d
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .xz at /usr/bin/xzdec
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .lzma at /usr/bin/xz -dc --format=lzma
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .lrz at /usr/bin/lrzip -q -k -d -o -
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .lzo at /usr/bin/lzop -d
    Jul 17 16:39:48 tn3 amavis[2562]: No ext program for .lz4, tried: lz4c -d
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .rpm at /usr/bin/rpm2cpio
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .cpio at /usr/bin/pax
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .tar at /usr/bin/pax
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .deb at /usr/bin/ar
    Jul 17 16:39:48 tn3 amavis[2562]: No ext program for .rar, tried: unrar, rar
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .arj at /usr/bin/unarj
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .arc at /usr/bin/nomarch
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .zoo at /usr/bin/unzoo
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .cab at /usr/bin/cabextract
    Jul 17 16:39:48 tn3 amavis[2562]: Internal decoder for .tnef
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .zip at /usr/bin/7za
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .kmz at /usr/bin/7za
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .7z at /usr/bin/7za
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .jar at /usr/bin/7z
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .rar at /usr/bin/7z
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .swf at /usr/bin/7z
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .lha at /usr/bin/7z
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .iso at /usr/bin/7z
    Jul 17 16:39:48 tn3 amavis[2562]: Found decoder for .exe at /usr/bin/unarj
    Jul 17 16:39:48 tn3 amavis[2562]: No decoder for .lz4
    Jul 17 16:39:48 tn3 amavis[2562]: Deleting db files snmp.db,__db.003,__db.002,nanny.db,__db.001 in /home/amavis/db
    Jul 17 16:39:48 tn3 amavis[2562]: Creating db in /home/amavis/db/; BerkeleyDB 0.51, libdb 5.3
    Jul 17 16:39:48 tn3 amavis[2562]: initializing Mail::SpamAssassin (0)
    Jul 17 16:39:51 tn3 amavis[2562]: SpamControl: init_pre_fork on SpamAssassin done
    Jul 17 16:39:51 tn3 amavis[2562]: extra modules loaded after daemonizing/chrooting: /usr/share/perl5/Net/libnet.cfg, Mail/SpamAssassin/Plugin/FreeMail.pm, Mail/SpamAssassin/Plugin/SpamCop.pm, Net/Cmd.pm, Net/Config.pm, Net/SMTP.pm
     
  11. Scott Horton

    Scott Horton New Member

    So next I kill the manual running program with:
    /usr/sbin/amavisd -c /etc/amavisd/amavisd.conf reload

    maillog says:
    Jul 17 16:42:42 tn3 amavis[2661]: Valid PID file (younger than sys uptime 0 0:18:00)
    Jul 17 16:42:42 tn3 amavis[2562]: Net::Server: Received a SIG HUP
    Jul 17 16:42:42 tn3 amavis[2562]: Net::Server: 2016/07/17-16:42:42 Server closing!
    Jul 17 16:42:42 tn3 amavis[2562]: Net::Server: Sending children hup signal
    Jul 17 16:42:42 tn3 amavis[2562]: (!)Net::Server: 2016/07/17-16:42:42 Re-exec server during HUP
    Jul 17 16:42:42 tn3 postfix/smtpd[2633]: disconnect from localhost[127.0.0.1]

    I verify, no amavisd processes running via ps ax|grep amav

    That sucker will not start....

    [root@tn3 ~]# systemctl start amavisd
    Job for amavisd.service failed because the control process exited with error code. See "systemctl status amavisd.service" and "journalctl -xe" for details.
    [root@tn3 ~]# systemctl status amavisd.service
    * amavisd.service - Amavisd-new is an interface between MTA and content checkers.
    Loaded: loaded (/usr/lib/systemd/system/amavisd.service; enabled; vendor preset: disabled)
    Active: failed (Result: start-limit) since Sun 2016-07-17 16:44:40 CDT; 3s ago
    Docs: http://www.ijs.si/software/amavisd/#doc
    Process: 2771 ExecStart=/usr/sbin/amavisd -c /etc/amavisd/amavisd.conf (code=exited, status=13)

    Jul 17 16:44:40 tn3.myserver.org systemd[1]: amavisd.service: control process exited, code=exited status=13
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: Failed to start Amavisd-new is an interface between MTA and content checkers..
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: Unit amavisd.service entered failed state.
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: amavisd.service failed.
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: amavisd.service holdoff time over, scheduling restart.
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: start request repeated too quickly for amavisd.service
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: Failed to start Amavisd-new is an interface between MTA and content checkers..
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: Unit amavisd.service entered failed state.
    Jul 17 16:44:40 tn3.myserver.org systemd[1]: amavisd.service failed.

    HELP!
     
  12. Scott Horton

    Scott Horton New Member

    Edited /etc/systemd/system/multi-user.target.wants/amavisd.service commented out the line that said
    # Wants=[email protected]
    Restarted postfix and tried to start amavisd - no dice.
     

Share This Page