Ping a Specific Port

Question

randomnickname

Asked: 2016-08-27 23:07:47 +0800 CST2016-08-27 23:07:47 +0800 CST 2016-08-27 23:07:47 +0800 CST

amavisd-new freezes: "Address already in use"

772

I have a mail server setup running on my Debian Jessie VPS which includes postfix, amavisd-new, SpamAssassin and a few other services.

All in all it seems my setup works pretty well and handles incoming mails correctly, however from time to time amavisd-new freezes ('systemctl status amavis.service' shows 'active (exited)').

Based on the amavisd-new logs I suppose it is caused by SpamAssassin's update job, which from my understanding fails to shut down amavisd-new properly; still, I can't make any sense of it.

Amavisd-new is in version 1:2.10.1-2~deb8u1, SpamAssassin is in version 3.4.1-3~bpo8+1.

Does anybody have a suggestion how to correct this or where to dig deeper?

Here is what amavis logs (with verbosity level set to 5) right before the freeze:

Aug 27 06:58:00 server.example.com /usr/sbin/amavisd-new[2476]: Net::Server: 2016/08/27-06:57:57 Server closing!
Aug 27 06:58:01 server.example.com /usr/sbin/amavisd-new[2476]: Net::Server: Kill TERM pid 2496
Aug 27 06:58:01 server.example.com /usr/sbin/amavisd-new[2476]: Net::Server: Kill TERM pid 2495
Aug 27 06:58:05 server.example.com /usr/sbin/amavisd-new[2495]: child_goes_idle (child finishing)
Aug 27 06:58:08 server.example.com /usr/sbin/amavisd-new[2495]: child_goes_idle: disconnected none (child finishing)
Aug 27 06:58:06 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) child_goes_idle (child finishing)
Aug 27 06:58:10 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) child_goes_idle: disconnected none (child finishing)
Aug 27 06:58:10 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) SA rundown_child (0)
Aug 27 06:58:10 server.example.com /usr/sbin/amavisd-new[2495]: SA rundown_child (0)
Aug 27 06:58:13 server.example.com /usr/sbin/amavisd-new[13635]: logging initialized, log level 5, logfile: /var/log/amavis.log
Aug 27 06:58:13 server.example.com /usr/sbin/amavisd-new[13635]: starting. /usr/sbin/amavisd-new at server.example.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_ALL="C", LANG="de_DE.UTF-8"
Aug 27 06:58:13 server.example.com /usr/sbin/amavisd-new[13635]: perl=5.020002, user=, EUID: 119 (119);  group=, EGID: 126 126 (126 126)
Aug 27 06:58:17 server.example.com /usr/sbin/amavisd-new[13635]: INFO: no optional modules: unicore::lib::Perl::SpacePer.pl unicore::lib::Nt::De.pl Unix::Getrusage
Aug 27 06:58:17 server.example.com /usr/sbin/amavisd-new[13635]: SpamControl: attempting to load scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Aug 27 06:58:17 server.example.com /usr/sbin/amavisd-new[13635]: SpamControl: scanner SpamAssassin, module Amavis::SpamControl::SpamAssassin
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) SpamControl: rundown_child on SpamAssassin done
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[2495]: SpamControl: rundown_child on SpamAssassin done
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) child_finish_hook: invoking DESTROY methods
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[2495]: child_finish_hook: invoking DESTROY methods
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13635]: INFO: SA version: 3.4.1, 3.004001, no optional modules: Net::CIDR::Lite Encode::Detect Image::Info Image::Info::GIF Image::Info::JPEG Image::Info::PNG Image::Info::BMP Image::Info::TIFF
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13635]: SpamControl: init_pre_chroot on SpamAssassin done
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13635]: socket module IO::Socket::IP, protocol families available: INET, INET6
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13635]: bind to /var/lib/amavis/amavisd.sock|unix, 127.0.0.1:10024/tcp, [::1]:10024/tcp
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: Net::Server: Process Backgrounded
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: Net::Server: 2016/08/27-06:58:24 Amavis (type Net::Server::PreForkSimple) starting! pid(13643)
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: Net::Server: Binding to UNIX socket file "/var/lib/amavis/amavisd.sock"
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: Net::Server: Binding to TCP port 10024 on host 127.0.0.1 with IPv4
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: (!)Net::Server: 2016/08/27-06:58:24 Can't connect to TCP port 10024 on 127.0.0.1 [Address already in use]\n  at line 68 in file /usr/share/perl5/Net/Server/Proto/TCP.pm
Aug 27 06:58:24 server.example.com /usr/sbin/amavisd-new[13643]: Net::Server: 2016/08/27-06:58:24 Server closing!
Aug 27 06:58:26 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) TempDir::DESTROY called
Aug 27 06:58:32 server.example.com /usr/sbin/amavisd-new[2495]: Amavis::DB::SNMP DESTROY called
Aug 27 06:58:32 server.example.com /usr/sbin/amavisd-new[2496]: (02496-01) Amavis::DB::SNMP DESTROY called

Any help is highly appreciated. Thanks in advance!

EDIT:

systemctl status amavis.service gives the following:

● amavis.service - LSB: Starts amavisd-new mailfilter
   Loaded: loaded (/etc/init.d/amavis; generated; vendor preset: enabled)
   Active: active (exited) since Do 2016-12-01 07:06:25 CET; 5h 41min ago
     Docs: man:systemd-sysv-generator(8)
  Process: 6971 ExecStop=/etc/init.d/amavis stop (code=exited, status=0/SUCCESS)
  Process: 6981 ExecStart=/etc/init.d/amavis start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/amavis.service

Dez 01 07:06:03 server systemd[1]: Starting LSB: Starts amavisd-new mailfilter...
Dez 01 07:06:14 server amavis[6987]: starting. /usr/sbin/amavisd-new at server.example.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_AL
Dez 01 07:06:25 server amavis[7000]: (!)Net::Server: 2016/12/01-07:06:25 Can't connect to TCP port 10024 on 127.0.0.1 [Address already in use]\
Dez 01 07:06:27 server amavis[6981]: Starting amavisd: amavisd-new.
Dez 01 07:06:25 server systemd[1]: Started LSB: Starts amavisd-new mailfilter.

I scanned today's mail.log and found the following info:

Dec  1 07:05:55 server spamd[14187]: spamd: server hit by SIGHUP, restarting
Dec  1 07:05:56 server spamd[14187]: spamd: child [14196] killed successfully: interrupted, signal 2 (0002)
Dec  1 07:05:56 server spamd[14187]: spamd: child [14197] killed successfully: interrupted, signal 2 (0002)
Dec  1 07:06:02 server spamd[14187]: spamd: server socket closed, type IO::Socket::IP
Dec  1 07:06:03 server spamd[14187]: spamd: server socket closed, type IO::Socket::IP
Dec  1 07:06:13 server spamd[14187]: logger: removing stderr method
Dec  1 07:06:14 server amavis[6987]: starting. /usr/sbin/amavisd-new at server.example.com amavisd-new-2.10.1 (20141025), Unicode aware, LC_ALL="C", LANG="de_DE.UTF-8"
Dec  1 07:06:15 server spamd[6995]: zoom: able to use 342/342 'body_0' compiled rules (100%)
Dec  1 07:06:25 server amavis[7000]: (!)Net::Server: 2016/12/01-07:06:25 Can't connect to TCP port 10024 on 127.0.0.1 [Address already in use]\n  at line 68 in file /usr/share/perl5/Net/Server/Proto/TCP.pm
Dec  1 07:06:32 server spamd[6995]: spamd: server started on IO::Socket::IP [127.0.0.1]:783, IO::Socket::IP [::1]:783 (running version 3.4.0)
Dec  1 07:06:34 server spamd[6995]: spamd: server pid: 6995
Dec  1 07:06:34 server spamd[6995]: spamd: server successfully spawned child process, pid 7005
Dec  1 07:06:34 server spamd[6995]: spamd: server successfully spawned child process, pid 7006
Dec  1 07:06:34 server spamd[6995]: prefork: child states: II

This leads me to the idea that it might be spamd itself which restarts my amavis daemon. But how can I find out, what process always restarts spamd?

1 Answers

Voted

Ryan Babchishin · Answer 1 · 2016-08-28T06:36:16+08:00

Ryan Babchishin

2016-08-28T06:36:16+08:002016-08-28T06:36:16+08:00

Where to dig deeper?

It's like two copies are starting at the same time... can you prevent systemd or whatever from starting amavisd-new and run it yourself from the command line?

See the man page. There's are debug modes and a foreground mode.

http://manpages.ubuntu.com/manpages/trusty/man8/amavisd-new.8.html

       debug  Runs amavisd-new in debug mode

       debug-sa
              Runs amavisd-new in spamassassin debug mode

       foreground
              Does not fork to background

0

amavisd-new freezes: "Address already in use"

Can you pass user/pass for HTTP Basic Authentication in URL parameters?

Ping a Specific Port

Check if port is open or closed on a Linux server?

How to automate SSH login with password?

How do I tell Git for Windows where to find my private RSA key?

What's the default superuser username/password for postgres after a new install?

What port does SFTP use?

Command line to list users in a Windows Active Directory group?

What is a Pem file and how does it differ from other OpenSSL Generated Key File Formats?

How to determine if a bash variable is empty?