У меня есть почтовый сервер, работающий на моем Debian Jessie VPS, который включает postfix, amavisd-new, SpamAssassin и несколько других служб.
Все в порядке. кажется, моя установка работает довольно хорошо и правильно обрабатывает входящую почту, однако время от времени amavisd-new зависает ('systemctl status amavis.service' показывает 'active (exited)').
На основе журналов amavisd-new Я полагаю, это вызвано обновлением SpamAssassin, которое, насколько я понимаю, не может правильно завершить работу amavisd-new; тем не менее, я могу ' В этом нет никакого смысла.
Amavisd-new в версии 1: 2.10.1-2 ~ deb8u1, SpamAssassin в версии 3.4.1-3 ~ bpo8 + 1.
Есть ли у кого-нибудь предложения, как исправить это или где копать глубже?
Вот какие журналы amavis (с уровнем детализации 5) прямо перед зависанием:
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
Любая помощь приветствуется. Заранее спасибо!
РЕДАКТИРОВАТЬ:
systemctl status amavis.service
дает следующее:
● 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.
Я просмотрел сегодняшний mail.log и нашел следующую информацию:
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
Это наводит меня на мысль, что это может быть сам спам, который перезапускает мой демон amavis. Но как мне узнать, какой процесс всегда перезапускает spamd?
Куда копать глубже?
Как будто две копии запускаются одновременно ... вы можете запретить systemd или чему-то еще запускать amavisd-new и запустить его самостоятельно из командной строки ?
См. Справочную страницу. Есть режимы отладки и режим переднего плана.
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