Hello when sending each incoming mail to spamassassin through spamd, I noticed it took a very long time to process them. Looking at syslog traces, one can see that each mail take 15 sec to be processed, which is not normal behaviour, checking all spam rules should take 2-3 sec at most. For example, these are the logs from spamd.log : Tue Jun 21 07:42:03 2016 [26023] info: spamd: connection from pulsar [::1]:41247 to port 783, fd 6 Tue Jun 21 07:42:03 2016 [26023] info: spamd: setuid to npomarede succeeded Tue Jun 21 07:42:03 2016 [26023] info: spamd: processing message <D776FA7A-2F0A-483E-BDC1-80991E4BBCE0@mail.6brent.info> for npomarede:500 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53 Tue Jun 21 07:42:03 2016 [26023] warn: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53 Tue Jun 21 07:42:03 2016 [26023] info: dns: bad dns reply: bgread: recv() failed: Connection refused at /usr/lib/perl5/vendor_perl/5.20.1/Mail/SpamAssassin/DnsResolver.pm line 743, <GEN3720> line 90. Tue Jun 21 07:42:03 2016 [26023] info: dns: bad dns reply: bgread: recv() failed: Connection refused at /usr/lib/perl5/vendor_perl/5.20.1/Mail/SpamAssassin/DnsResolver.pm line 743. Tue Jun 21 07:42:06 2016 [26023] info: dns: bad dns reply: bgread: recv() failed: Connection refused at /usr/lib/perl5/vendor_perl/5.20.1/Mail/SpamAssassin/DnsResolver.pm line 743. Tue Jun 21 07:42:09 2016 [26023] info: dns: bad dns reply: bgread: recv() failed: Connection refused at /usr/lib/perl5/vendor_perl/5.20.1/Mail/SpamAssassin/DnsResolver.pm line 743. Tue Jun 21 07:42:12 2016 [26023] info: dns: bad dns reply: bgread: recv() failed: Connection refused at /usr/lib/perl5/vendor_perl/5.20.1/Mail/SpamAssassin/DnsResolver.pm line 743. Tue Jun 21 07:42:18 2016 [26023] info: spamd: identified spam (11.7/5.0) for npomarede:500 in 15.0 seconds, 2940 bytes. Tue Jun 21 07:42:18 2016 [26023] info: spamd: result: Y 11 - ADVANCE_FEE_5_NEW,BAYES_50,DEAR_BENEFICIARY,FREEMAIL_FORGED_REPLYTO,FREEMAIL_REPLYTO_END_DIGIT,HK_NAME_MR_MRS,HTML_MESSAGE,RDNS_NONE,SUBJ_ALL_CAPS,TVD_PH_BODY_META,T_SPF_HELO_TEMPERROR,T_SPF_TEMPERROR scantime=15.0,size=2940,user=npomarede,uid=500,required_score=5.0,rhost=pulsar,raddr=::1,rport=41247,mid=<D776FA7A-2F0A-483E-BDC1-80991E4BBCE0@mail.6brent.info>,bayes=0.497152,autolearn=no autolearn_force=no Tue Jun 21 07:42:18 2016 [2035] info: prefork: child states: II -> mail is received at 07:42:03 and process ended at 07:42:18, with lots of DNS error As described here https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=741521 , the problem is that spamassassin uses his own DNS resolver and gets his list of DNS servers by reading /etc/resolv.conf when spamd is started But when spamd starts at boot, network is not necessarily up yet, so /etc/resolv.conf will be empty and spamd will default to 127.0.0.1 and unless you have a local DNS resolver, this will fail. This is similar to https://bugs.mageia.org/show_bug.cgi?id=17219 affecting dovecot : /usr/lib/systemd/system/spamd.service waits for "network.target" but it should wait for "network-online.target" Another solution would be to restart spamd each time an interface becomes up, so if your wifi network changes, then spamd gets the new DNS servers, but I don't know if such triggers are possible ? At least, changing /usr/lib/systemd/system/spamd.service should fix the problem in most cases. From what I see, this should also be updated in cauldron for the soon to be released mageia 6.
Assigning to maintainer
Source RPM: spamassassin-spamd-3.4.1-1.mga5 => spamassassin-3.4.1-1.mga5CC: (none) => marja11Assignee: bugsquad => remco
Ping, anyone to change /usr/lib/systemd/system/spamd.service and use "network-online.target" instead ? This should not have any negative impact.
(In reply to Nicolas Pomarède from comment #2) > Ping, anyone to change /usr/lib/systemd/system/spamd.service and use > "network-online.target" instead ? This should not have any negative impact. Hi Nicolas, Thank you for having taken the needed time to report this issue! Did this bug get fixed? If so, please change its status to RESOLVED - FIXED If it didn't, then we regret that we weren't able to fix it in Mageia 5. Mageia 5 has officially reached its End of Life on December 31st, 2017 https://blog.mageia.org/en/2017/11/07/mageia-5-eol-postponed/ It only continued to get important security updates since then, because we are waiting for a big Plasma5 update in Mageia 6, that'll fix many of the Mageia 5 => 6 upgrade issues. If you haven't seen that this bug got fixed, then please check whether this bug still exists in Mageia 6. If it does, then please change the Version (near the top, at the left) to "6". If you know it exists in Cauldron, then change Version to Cauldron. If you see it in both Cauldron and Mageia 6, then please set Version to Cauldron and add MGA6TOO on the Whiteboard. Thanks, Marja (In case this report needs to stay open for a supported release: Reassigning to all packagers collectively, since there is no longer a registered maintainer for spamassassin, and CC'ing Neal, because he works on systemd a lot)
Assignee: remco => pkg-bugsCC: (none) => ngompa13Source RPM: spamassassin-3.4.1-1.mga5 => spamassassin-3.4.1-1.mga5, systemd
Hi just checked on latest cauldron version spamassassin-spamd-3.4.1-5.mga7.x86_64.rpm and the issue is still there : This is the start of /usr/lib/systemd/system/spamd.service : [Unit] Description=Spamassassin daemon After=syslog.target network.target As can be seen, it still uses network.target instead of network-online.target which means spamd will have bad dns timeout in case it starts too fast before network (and dns) are really up. Bug status updated as requested.
Whiteboard: (none) => MGA6TOOVersion: 5 => Cauldron
Ping this bug
Whiteboard: MGA6TOO => MGA7TOOTarget Milestone: --- => Mageia 7Severity: normal => majorCC: (none) => ouaurelien
This dns problem can appear or not depending on how fast the network target starts after a reboot. I didn't see it recently, but I see that under mageia 7 spamd.service still uses : [Unit] Description=Spamassassin daemon After=syslog.target network.target I think it would be safer to use "network-online.target" instead. Maybe it's already the case under cauldron/mageia 8, can't check at the moment.