我有 Postfix、Postgrey、Spamassassin、amavisd-new 和 dovecot 设置。
当我通过系统发送电子邮件时,日志文件就完全变得混乱。
我找不到任何信息来解释日志行的含义,所以我不确定在这里发布什么内容最好。它看起来回到了我 6 个月前安装服务器时的一些信息,并为之前处理的大量消息提供了日志行。
这会导致日志文件变得非常大(我的 mail.log.1 今天早上切换了,大小为 331 Gb)。mail.log 目前最大可达 34 Gb。
以下是正在记录的行的示例。有数千行这样的行,其中“spamfilter:”后的日期不断增加,直到达到当前日期。
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:11:34 2016 [2758] info: spamd: connection from ip6-localhost [::1]:54602 to port 783, fd 5
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:11:34 2016 [2758] info: spamd: processing message (unknown) for spamd:5001
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:11:36 2016 [2758] info: spamd: clean message (2.8/5.0) for spamd:5001 in 2.2 seconds, 52500 bytes.
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:11:36 2016 [2758] info: spamd: result: . 2 - BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,MISSING_MID,NORMAL_HTTP_TO_IP,NO_RECEIVED,NO_RELAYS,RAZOR2_CF_RANGE_51_100,RAZOR2_CF_RANGE_E8_51_100,RAZOR2_CHECK,URIBL_BLOCKED,URI_DQ_UNSUB scantime=2.2,size=52500,user=spamd,uid=5001,required_score=5.0,rhost=ip6-localhost,raddr=::1,rport=54602,mid=(unknown),bayes=0.000000,autolearn=no autolearn_force=no
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:11:36 2016 [2756] info: prefork: child states: II
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:16:39 2016 [2758] info: spamd: connection from ip6-localhost [::1]:54668 to port 783, fd 5
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:16:39 2016 [2758] info: spamd: processing message <[email protected]> for spamd:5001
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:16:41 2016 [2758] info: spamd: clean message (-1.8/5.0) for spamd:5001 in 1.8 seconds, 11325 bytes.
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:16:41 2016 [2758] info: spamd: result: . -1 - BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,NO_RECEIVED,NO_RELAYS,PP_MIME_FAKE_ASCII_TEXT,URIBL_BLOCKED scantime=1.8,size=11325,user=spamd,uid=5001,required_score=5.0,rhost=ip6-localhost,raddr=::1,rport=54668,mid=<[email protected]>,bayes=0.000000,autolearn=no autolearn_force=no
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:16:41 2016 [2756] info: prefork: child states: II
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:12 2016 [2758] info: spamd: connection from ip6-localhost [::1]:54698 to port 783, fd 5
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:12 2016 [2758] info: spamd: processing message <[email protected]> for spamd:5001
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:12 2016 [2759] info: spamd: connection from ip6-localhost [::1]:54700 to port 783, fd 5
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:12 2016 [2759] info: spamd: processing message <[email protected]> for spamd:5001
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2758] info: spamd: clean message (-1.8/5.0) for spamd:5001 in 1.6 seconds, 11288 bytes.
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2758] info: spamd: result: . -1 - BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,NO_RECEIVED,NO_RELAYS,PP_MIME_FAKE_ASCII_TEXT,URIBL_BLOCKED scantime=1.6,size=11288,user=spamd,uid=5001,required_score=5.0,rhost=ip6-localhost,raddr=::1,rport=54698,mid=<[email protected]>,bayes=0.000000,autolearn=no autolearn_force=no
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2756] info: prefork: child states: IB
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2759] info: spamd: clean message (-1.8/5.0) for spamd:5001 in 1.7 seconds, 11288 bytes.
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2759] info: spamd: result: . -1 - BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,HTML_MESSAGE,NO_RECEIVED,NO_RELAYS,PP_MIME_FAKE_ASCII_TEXT,URIBL_BLOCKED scantime=1.7,size=11288,user=spamd,uid=5001,required_score=5.0,rhost=ip6-localhost,raddr=::1,rport=54700,mid=<[email protected]>,bayes=0.000000,autolearn=no autolearn_force=no
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:17:14 2016 [2756] info: prefork: child states: II
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:20:21 2016 [2758] info: spamd: connection from ip6-localhost [::1]:54760 to port 783, fd 5
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:20:21 2016 [2758] info: spamd: processing message <000601d2269a$90c7d4c0$c93956a9@LocalHost4dh> for spamd:5001
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:20:23 2016 [2758] info: spamd: clean message (3.8/5.0) for spamd:5001 in 2.0 seconds, 5992 bytes.
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:20:23 2016 [2758] info: spamd: result: . 3 - BAYES_05,HTML_MESSAGE,MIME_HTML_ONLY,NO_RECEIVED,NO_RELAYS,RATWARE_OUTLOOK_NONAME,URIBL_BLOCKED,URIBL_PH_SURBL scantime=2.0,size=5992,user=spamd,uid=5001,required_score=5.0,rhost=ip6-localhost,raddr=::1,rport=54760,mid=<000601d2269a$90c7d4c0$c93956a9@LocalHost4dh>,bayes=0.029870,autolearn=no autolearn_force=no
Apr 2 10:31:26 oss2 spamfilter: Sat Oct 15 13:20:23 2016 [2756] info: prefork: child states: II
我确信这种行为是错误的,但我不知道它为什么会这样做。我查看了几个 Spamassassin 配置教程,但没有任何东西能告诉我该去哪里查看。
如果有人能告诉我如何修复这个问题,那就太好了。如果做不到,请告诉我为什么它会在处理每封电子邮件时重复这些日志行,以及我可能从哪里开始寻找解决方案。
如果需要更多信息,请告诉我您需要什么。我不想在这个帖子里充斥着配置文件和更多不必要的日志信息。
答案1
非常感谢 Spamassassin 用户邮件列表中知识渊博的人,我终于找到了这个问题的根源并将其解决了。
通过我的邮件服务器配置过程,我最终得到了一个帮助脚本 /usr/bin/spamfilter.sh
该脚本正在写入日志文件 (/var/log/spamassassin/spamd.log),该文件未包含在 logrotate 系统中。logrotate.d 目录包含一个用于轮换 /var/log/spamd.log 的配置文件。这(拼写错误?)意味着它一直在增长。
每次系统处理新消息时,都会读取该日志文件中的所有内容并将其重新记录到 mail.log 和 syslog 中。
我已经解决了该问题,方法是修复 spamfilter.sh 中的引用以使用 /var/log/spamd.log 文件,该文件将每天轮换一次,从而防止大量消息积累并重新记录。
我希望这对其他人有所帮助,但我要特别感谢 Spamassassin 用户邮件列表中的以下用户的帮助和专家建议:
- 凯文·麦克格雷尔
- 约翰·哈丁
- 戴夫·瑞斯基
- ap-ml
- 汤姆·亨德里克斯
你们干得太棒了。非常感谢。