我在我的 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
这让我想到,可能是 spamd 本身重新启动了我的 amavis 守护进程。但我如何才能找出哪个进程总是重新启动 spamd?
答案1
在哪里可以深入挖掘?
这就像两个副本同时启动……您可以阻止 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