Cannot start amavisd as a service on OpenSuSE 13.1

Hi there,

I got this weird problem when trying to start amavisd as a service on OpenSuSE 13.1. When I run:

service amavis start

I can see amavis starting up nicely as it shoud:

ps auxwww | grep amavis
root     11178  0.0  0.0   4788  1244 pts/1    S+   23:17   0:00 /bin/bash /sbin/service amavis start
root     11179  0.0  0.0   4300  1008 pts/1    S+   23:17   0:00 systemctl start amavis.service
vscan    11186 32.0  3.2  79624 68092 ?        Ss   23:17   0:03 /usr/sbin/amavisd (master)              
vscan    11189  0.1  3.2  80600 67224 ?        S    23:17   0:00 /usr/sbin/amavisd (virgin child)        
vscan    11190  0.1  3.2  80600 67184 ?        S    23:17   0:00 /usr/sbin/amavisd (virgin child)        
vscan    11191  0.0  3.2  80600 67208 ?        S    23:17   0:00 /usr/sbin/amavisd (virgin child)        
vscan    11192  0.0  3.2  80600 67180 ?        S    23:17   0:00 /usr/sbin/amavisd (virgin child)        
root     11194  0.0  0.0   4380   852 pts/0    S+   23:17   0:00 grep --color=auto amavis 

and in /var/log/mail, I get:

2014-03-11T23:17:42.942166+01:00 lucy amavis[11184]: starting. /usr/sbin/amavisd at mail.weverstv amavisd-new-2.8.1 (20130628), Unicode aware, LC_CTYPE="en_US.UTF-8", LANG="POSIX"
2014-03-11T23:17:43.658522+01:00 lucy amavis[11186]: Net::Server: Group Not Defined.  Defaulting to EGID '496 496'
2014-03-11T23:17:43.663770+01:00 lucy amavis[11186]: Net::Server: User Not Defined.  Defaulting to EUID '65'
2014-03-11T23:17:43.718202+01:00 lucy amavis[11186]: Module Amavis::Conf        2.318
2014-03-11T23:17:43.722865+01:00 lucy amavis[11186]: Module Archive::Zip        1.30
2014-03-11T23:17:43.724717+01:00 lucy amavis[11186]: Module BerkeleyDB          0.52
2014-03-11T23:17:43.727386+01:00 lucy amavis[11186]: Module Compress::Raw::Zlib 2.06
2014-03-11T23:17:43.728779+01:00 lucy amavis[11186]: Module Compress::Zlib      2.06
2014-03-11T23:17:43.730250+01:00 lucy amavis[11186]: Module Convert::TNEF       0.18
2014-03-11T23:17:43.733448+01:00 lucy amavis[11186]: Module Convert::UUlib      1.4
2014-03-11T23:17:43.734814+01:00 lucy amavis[11186]: Module Crypt::OpenSSL::RSA 0.28
2014-03-11T23:17:43.736992+01:00 lucy amavis[11186]: Module DB_File             1.828
2014-03-11T23:17:43.739034+01:00 lucy amavis[11186]: Module Digest::MD5         2.52
2014-03-11T23:17:43.740786+01:00 lucy amavis[11186]: Module Digest::SHA         5.84_01
2014-03-11T23:17:43.742862+01:00 lucy amavis[11186]: Module Digest::SHA1        2.13
2014-03-11T23:17:43.745587+01:00 lucy amavis[11186]: Module Encode              2.49
2014-03-11T23:17:43.747904+01:00 lucy amavis[11186]: Module File::Temp          0.23
2014-03-11T23:17:43.749658+01:00 lucy amavis[11186]: Module IO::Socket::INET6   2.71
2014-03-11T23:17:43.752184+01:00 lucy amavis[11186]: Module MIME::Entity        5.504
2014-03-11T23:17:43.754020+01:00 lucy amavis[11186]: Module MIME::Parser        5.504
2014-03-11T23:17:43.756119+01:00 lucy amavis[11186]: Module MIME::Tools         5.504
2014-03-11T23:17:43.757787+01:00 lucy amavis[11186]: Module Mail::DKIM::Signer  0.4
2014-03-11T23:17:43.759592+01:00 lucy amavis[11186]: Module Mail::DKIM::Verifier 0.4
2014-03-11T23:17:43.761387+01:00 lucy amavis[11186]: Module Mail::Header        2.12
2014-03-11T23:17:43.763651+01:00 lucy amavis[11186]: Module Mail::Internet      2.12
2014-03-11T23:17:43.765658+01:00 lucy amavis[11186]: Module Mail::SPF           v2.008
2014-03-11T23:17:43.767247+01:00 lucy amavis[11186]: Module Mail::SpamAssassin  3.003002
2014-03-11T23:17:43.768893+01:00 lucy amavis[11186]: Module Net::DNS            0.72
2014-03-11T23:17:43.770473+01:00 lucy amavis[11186]: Module Net::Server         2.007
2014-03-11T23:17:43.772120+01:00 lucy amavis[11186]: Module NetAddr::IP         4.069
2014-03-11T23:17:43.773802+01:00 lucy amavis[11186]: Module Razor2::Client::Version 2.84
2014-03-11T23:17:43.775528+01:00 lucy amavis[11186]: Module Scalar::Util        1.27
2014-03-11T23:17:43.777151+01:00 lucy amavis[11186]: Module Socket              2.009
2014-03-11T23:17:43.778736+01:00 lucy amavis[11186]: Module Socket6             0.23
2014-03-11T23:17:43.780373+01:00 lucy amavis[11186]: Module Time::HiRes         1.9725
2014-03-11T23:17:43.781956+01:00 lucy amavis[11186]: Module URI                 1.60
2014-03-11T23:17:43.783637+01:00 lucy amavis[11186]: Module Unix::Syslog        1.1
2014-03-11T23:17:43.785285+01:00 lucy amavis[11186]: Amavis::ZMQ code     NOT loaded
2014-03-11T23:17:43.786862+01:00 lucy amavis[11186]: Amavis::DB code      loaded
2014-03-11T23:17:43.788623+01:00 lucy amavis[11186]: Redis code           NOT loaded
2014-03-11T23:17:43.790314+01:00 lucy amavis[11186]: SQL base code        NOT loaded
2014-03-11T23:17:43.791987+01:00 lucy amavis[11186]: SQL::Log code        NOT loaded
2014-03-11T23:17:43.793787+01:00 lucy amavis[11186]: SQL::Quarantine      NOT loaded
2014-03-11T23:17:43.795422+01:00 lucy amavis[11186]: Lookup::SQL code     NOT loaded
2014-03-11T23:17:43.797191+01:00 lucy amavis[11186]: Lookup::LDAP code    NOT loaded
2014-03-11T23:17:43.798788+01:00 lucy amavis[11186]: AM.PDP-in proto code loaded
2014-03-11T23:17:43.800436+01:00 lucy amavis[11186]: SMTP-in proto code   loaded
2014-03-11T23:17:43.801995+01:00 lucy amavis[11186]: Courier proto code   NOT loaded
2014-03-11T23:17:43.803623+01:00 lucy amavis[11186]: SMTP-out proto code  loaded
2014-03-11T23:17:43.805590+01:00 lucy amavis[11186]: Pipe-out proto code  NOT loaded
2014-03-11T23:17:43.807460+01:00 lucy amavis[11186]: BSMTP-out proto code NOT loaded
2014-03-11T23:17:43.809128+01:00 lucy amavis[11186]: Local-out proto code loaded
2014-03-11T23:17:43.811073+01:00 lucy amavis[11186]: OS_Fingerprint code  NOT loaded
2014-03-11T23:17:43.813005+01:00 lucy amavis[11186]: ANTI-VIRUS code      loaded
2014-03-11T23:17:43.814756+01:00 lucy amavis[11186]: ANTI-SPAM code       loaded
2014-03-11T23:17:43.816565+01:00 lucy amavis[11186]: ANTI-SPAM-EXT code   NOT loaded
2014-03-11T23:17:43.818309+01:00 lucy amavis[11186]: ANTI-SPAM-C code     NOT loaded
2014-03-11T23:17:43.820192+01:00 lucy amavis[11186]: ANTI-SPAM-SA code    loaded
2014-03-11T23:17:43.821969+01:00 lucy amavis[11186]: Unpackers code       loaded
2014-03-11T23:17:43.823759+01:00 lucy amavis[11186]: DKIM code            loaded
2014-03-11T23:17:43.825711+01:00 lucy amavis[11186]: Tools code           NOT loaded
2014-03-11T23:17:43.827561+01:00 lucy amavis[11186]: Found $file            at /usr/bin/file
2014-03-11T23:17:43.829192+01:00 lucy amavis[11186]: No $altermime,         not using it
2014-03-11T23:17:43.830931+01:00 lucy amavis[11186]: Internal decoder for .mail
2014-03-11T23:17:43.832753+01:00 lucy amavis[11186]: No ext program for   .F, tried: unfreeze, freeze -d, melt, fcat
2014-03-11T23:17:43.834647+01:00 lucy amavis[11186]: Found decoder for    .Z    at /usr/bin/uncompress
2014-03-11T23:17:43.836495+01:00 lucy amavis[11186]: Found decoder for    .gz   at /usr/bin/gzip -d
2014-03-11T23:17:43.838248+01:00 lucy amavis[11186]: Found decoder for    .bz2  at /usr/bin/bzip2 -d
2014-03-11T23:17:43.840131+01:00 lucy amavis[11186]: Found decoder for    .xz   at /usr/bin/xzdec
2014-03-11T23:17:43.841906+01:00 lucy amavis[11186]: Found decoder for    .lzma at /usr/bin/lzmadec
2014-03-11T23:17:43.843815+01:00 lucy amavis[11186]: No ext program for   .lrz, tried: lrzip -q -k -d -o -, lrzcat -q -k
2014-03-11T23:17:43.845470+01:00 lucy amavis[11186]: No ext program for   .lzo, tried: lzop -d
2014-03-11T23:17:43.847241+01:00 lucy amavis[11186]: Found decoder for    .rpm  at /usr/bin/rpm2cpio
2014-03-11T23:17:43.848906+01:00 lucy amavis[11186]: Found decoder for    .cpio at /usr/bin/pax
2014-03-11T23:17:43.850597+01:00 lucy amavis[11186]: Found decoder for    .tar  at /usr/bin/pax
2014-03-11T23:17:43.852977+01:00 lucy amavis[11186]: No ext program for   .deb, tried: ar
2014-03-11T23:17:43.854910+01:00 lucy amavis[11186]: Found decoder for    .rar  at /usr/bin/unrar
2014-03-11T23:17:43.856795+01:00 lucy amavis[11186]: No ext program for   .arj, tried: unarj, arj
2014-03-11T23:17:43.858562+01:00 lucy amavis[11186]: No ext program for   .arc, tried: nomarch, arc
2014-03-11T23:17:43.860232+01:00 lucy amavis[11186]: Found decoder for    .zoo  at /usr/bin/zoo
2014-03-11T23:17:43.861923+01:00 lucy amavis[11186]: No ext program for   .doc, tried: ripole
2014-03-11T23:17:43.863585+01:00 lucy amavis[11186]: No ext program for   .cab, tried: cabextract
2014-03-11T23:17:43.865189+01:00 lucy amavis[11186]: No ext program for   .tnef, tried: tnef
2014-03-11T23:17:43.866779+01:00 lucy amavis[11186]: Internal decoder for .tnef
2014-03-11T23:17:43.868501+01:00 lucy amavis[11186]: No ext program for   .zip, tried: 7za, 7z
2014-03-11T23:17:43.870462+01:00 lucy amavis[11186]: No ext program for   .kmz, tried: 7za, 7z
2014-03-11T23:17:43.872176+01:00 lucy amavis[11186]: Internal decoder for .zip
2014-03-11T23:17:43.873765+01:00 lucy amavis[11186]: Internal decoder for .kmz
2014-03-11T23:17:43.875384+01:00 lucy amavis[11186]: No ext program for   .7z, tried: 7zr, 7za, 7z
2014-03-11T23:17:43.876966+01:00 lucy amavis[11186]: No ext program for   .7z, tried: 7za, 7z
2014-03-11T23:17:43.878525+01:00 lucy amavis[11186]: No ext program for   .jar, tried: 7z
2014-03-11T23:17:43.880162+01:00 lucy amavis[11186]: No ext program for   .arj, tried: 7z
2014-03-11T23:17:43.881827+01:00 lucy amavis[11186]: No ext program for   .swf, tried: 7z
2014-03-11T23:17:43.883513+01:00 lucy amavis[11186]: No ext program for   .lha, tried: 7z
2014-03-11T23:17:43.885101+01:00 lucy amavis[11186]: No ext program for   .iso, tried: 7z
2014-03-11T23:17:43.886661+01:00 lucy amavis[11186]: No ext program for   .cab, tried: 7z
2014-03-11T23:17:43.888299+01:00 lucy amavis[11186]: No ext program for   .deb, tried: 7z
2014-03-11T23:17:43.889872+01:00 lucy amavis[11186]: Found decoder for    .exe  at /usr/bin/unrar
2014-03-11T23:17:43.891513+01:00 lucy amavis[11186]: No decoder for       .7z
2014-03-11T23:17:43.893143+01:00 lucy amavis[11186]: No decoder for       .F
2014-03-11T23:17:43.897545+01:00 lucy amavis[11186]: No decoder for       .arc
2014-03-11T23:17:43.900685+01:00 lucy amavis[11186]: No decoder for       .arj
2014-03-11T23:17:43.902177+01:00 lucy amavis[11186]: No decoder for       .cab
2014-03-11T23:17:43.908264+01:00 lucy amavis[11186]: No decoder for       .deb
2014-03-11T23:17:43.909781+01:00 lucy amavis[11186]: No decoder for       .doc
2014-03-11T23:17:43.911139+01:00 lucy amavis[11186]: No decoder for       .iso
2014-03-11T23:17:43.912572+01:00 lucy amavis[11186]: No decoder for       .jar
2014-03-11T23:17:43.913920+01:00 lucy amavis[11186]: No decoder for       .lha
2014-03-11T23:17:43.916283+01:00 lucy amavis[11186]: No decoder for       .lrz
2014-03-11T23:17:43.918887+01:00 lucy amavis[11186]: No decoder for       .lzo
2014-03-11T23:17:43.920403+01:00 lucy amavis[11186]: No decoder for       .swf
2014-03-11T23:17:43.921772+01:00 lucy amavis[11186]: Using primary internal av scanner code for ClamAV-clamd
2014-03-11T23:17:43.923141+01:00 lucy amavis[11186]: Found secondary av scanner ClamAV-clamscan at /usr/bin/clamscan
2014-03-11T23:17:43.925012+01:00 lucy amavis[11186]: Deleting db files nanny.db,__db.001,__db.004,__db.002,__db.003,snmp.db in /var/spool/amavis/db
2014-03-11T23:17:43.926443+01:00 lucy amavis[11186]: Creating db in /var/spool/amavis/db/; BerkeleyDB 0.52, libdb 4.8 

The command starting the service then at some point fails:


# service amavis start
Job for amavis.service failed. See 'systemctl status amavis.service' and 'journalctl -xn' for details.

# systemctl status amavis.service
amavis.service - Amavisd-new Virus Scanner interface
   Loaded: loaded (/usr/lib/systemd/system/amavis.service; enabled)
   Active: failed (Result: timeout) since Tue 2014-03-11 23:19:11 CET; 3min 20s ago
  Process: 11184 ExecStart=/usr/sbin/amavisd start (code=exited, status=0/SUCCESS)
  Process: 11183 ExecStartPre=/usr/sbin/amavisd-milter.sh start (code=exited, status=0/SUCCESS)
  Process: 11181 ExecStartPre=/bin/echo Starting virus-scanner (amavisd-new): (code=exited, status=0/SUCCESS)

Mar 11 23:17:43 lucy amavis[11186]: No decoder for       .lrz
Mar 11 23:17:43 lucy amavis[11186]: No decoder for       .lzo
Mar 11 23:17:43 lucy amavis[11186]: No decoder for       .swf
Mar 11 23:17:43 lucy amavis[11186]: Using primary internal av scanner code for ClamAV-clamd
Mar 11 23:17:43 lucy amavis[11186]: Found secondary av scanner ClamAV-clamscan at /usr/bin/clamscan
Mar 11 23:17:43 lucy amavis[11186]: Deleting db files nanny.db,__db.001,__db.004,__db.002,__db.003,snmp.db in /var/spool/amavis/db
Mar 11 23:17:43 lucy amavis[11186]: Creating db in /var/spool/amavis/db/; BerkeleyDB 0.52, libdb 4.8
Mar 11 23:19:11 lucy systemd[1]: amavis.service operation timed out. Terminating.
Mar 11 23:19:11 lucy systemd[1]: Failed to start Amavisd-new Virus Scanner interface.
Mar 11 23:19:11 lucy systemd[1]: Unit amavis.service entered failed state. 

When I just run amavisd from the command line I get the same messages in /var/log/mail, but amavis just keeps on running.

Any suggestions on what can be wrong here? What is the service script waiting for?

Kind regards,
Louis

I see you did not get many answers/suggestions. Sorry, but I also can not realy help you. I did not even know what amavis is until I checked for it’s description in YaST > Software > Software management.

It seems to be a virus detecting software. That could explain why nobody until now answers here. Most of the people here do not use ant-virus software for the simple reason that they are using Linux. People here are aware that having a mail server that transfers mail to MicroSoft systems might include the need to check for MicroSoft aimed virusses in those “passing by” mails as a service to Windows users, but again, there aren’t many here that do that.

BTW, you are now using a mix of old (service) and new (systemctl) commands. While that still works, it is better go completely for systemclt imho.

I tested installing amavisd on a vanilla 13.1 fresh VM and it worked fine if I launched it from /etc/init.d/amavisd start

Have you made any changes to the /etc/amavisd.conf yourself or changes to postfix and/or clam? Also is this an upgraded installation or a fresh one?

Hi,

Yes, I’ve updated amavisd.conf to match my needs. Same goes for postfix. Clam I left untouched. The system was a fresh install, updated with the latest patches. So this is the point where I thank you. I did a fresh install of amavis to see if things would work “out of the box”. So they did (well, once I set $myhostname that is). And a quick test using my old amavisd.conf proved that my config was the one actually breaking it. (Though I still can’t tell why amavisd would run when not using as a service). Then again, the config was taken from my old CentOS 5 box (which is replaced by this one) so I guess some of the settings there are not really liked by the service command here.

To be more precise, it’s this little bugger that broke it:


$pid_file  = "$MYHOME/var/amavisd.pid";   # -P

So one happy peguin over here again.

Many thanks,
Louis

P.S. @hcvv, The combination of amavis with clam and spamassassin provide server side virus and spam detection. As this is a mailserver for several others as well (and some of them use this other OS), I have the server side virus scanner in place, just as an extra service.

Exactly the usage I spoke of.

What I wanted with my post were two things:

  1. seeing that there wasn’t much reaction to it, to give it a bummer;
  2. warning you that experience and thus reactions might be minimal here.

It seems that my post served it’s purpose and that you are a happy user again.:wink:

Yes it did. Thanks. I’m happy again.

Louis