Google Groups no longer supports new Usenet posts or subscriptions. Historical content remains viewable.
Dismiss
Bug#1034427: spamd fails to filter
370 views
Skip to first unread message
Ed Lawson
Apr 14, 2023, 8:40:05 PM4/14/23
to
Package: spamd
Version: 4.0.0-4
Severity: important
X-Debbugs-Cc: ela...@grizzy.com
Dear Maintainer,
*** Reporter, please consider answering these questions, where appropriate ***
* What led up to the situation?
AI have run Sid for years and with a few issues had a working
spamfiltering system using spamd and the claws plugin. A few months
ago I noticed that although Claws indicated spamassassin was
filtering the mail, no mail was being filtered and send to the spam
folder. I checked the configuration of Spamassassin and the claws
plug in and nothing seemed to be wrong or different from when the
system performed properly.
the syslog entires suggest something spamd is in fact trying to
work, but for various reasons it aborts. Here are the entires from
syslog.
2023-04-14T11:16:57.933705-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:52922 to port 783, fd 5
2023-04-14T11:16:57.938346-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:16:57.944632-04:00 800-mini-1 spamd[905]: spamd: checking message <eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8> for elawson:1000
2023-04-14T11:17:01.051774-04:00 800-mini-1 CRON[5905]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
2023-04-14T11:17:08.848257-04:00 800-mini-1 spamd[905]: async: aborting after 10.851 s, deadline shrunk: DNSBL, A/188.100.89.167.psbl.surriel.com, rules: RCVD_IN_PSBL
2023-04-14T11:17:08.848465-04:00 800-mini-1 spamd[905]: async: aborting after 10.853 s, deadline shrunk: DNSBL, A/188.100.89.167.zen.spamhaus.org, rules: RCVD_IN_PBL, __RCVD_IN_ZEN, RCVD_IN_ZEN_BLOCKED_OPENDNS, RCVD_IN_ZEN_BLOCKED, RCVD_IN_XBL
2023-04-14T11:17:08.848535-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, TXT/188.100.89.167.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:17:08.848592-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, TXT/188.100.89.167.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
2023-04-14T11:17:08.848682-04:00 800-mini-1 spamd[905]: async: aborting after 10.848 s, deadline shrunk: AskDNS, A/ebay.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
2023-04-14T11:17:08.848844-04:00 800-mini-1 spamd[905]: async: aborting after 10.852 s, deadline shrunk: DNSBL, A/188.100.89.167.list.dnswl.org, rules: __RCVD_IN_DNSWL
2023-04-14T11:17:08.848984-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, A/188.100.89.167.dnsbl.sorbs.net, rules: __RCVD_IN_SORBS, RCVD_IN_SORBS_DUL
2023-04-14T11:17:08.912069-04:00 800-mini-1 spamd[905]: spamd: clean message (-17.0/2.0) for elawson:1000 in 11.0 seconds, 97709 bytes.
2023-04-14T11:17:08.912273-04:00 800-mini-1 spamd[905]: spamd: result: . -16 - DKIMWL_WL_HIGH,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_IMAGE_RATIO_08,HTML_MESSAGE,MIME_HTML_ONLY,RCVD_IN_MSPIKE_H2,SPF_PASS,T_KAM_HTML_FONT_INVALID,T_SPF_HELO_TEMPERROR,USER_IN_DEF_DKIM_WL,USER_IN_DEF_SPF_WL scantime=11.0,size=97709,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=52922,mid=<eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8>,autolearn=ham autolearn_force=no
2023-04-14T11:22:10.970820-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:35172 to port 783, fd 5
2023-04-14T11:22:10.974041-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:22:10.980913-04:00 800-mini-1 spamd[905]: spamd: checking message <1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net> for elawson:1000
2023-04-14T11:22:13.554862-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 504 bytes
2023-04-14T11:22:13.575439-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 124 bytes
2023-04-14T11:22:20.062314-04:00 800-mini-1 spamd[905]: async: aborting after 9.023 s, deadline shrunk: DNSBL, TXT/127.18.247.158.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:22:20.062535-04:00 800-mini-1 spamd[905]: async: aborting after 9.022 s, deadline shrunk: DNSBL, A/127.18.247.158.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
2023-04-14T11:22:20.062610-04:00 800-mini-1 spamd[905]: async: aborting after 9.025 s, deadline shrunk: DNSBL, A/127.18.247.158.zen.spamhaus.org, rules: RCVD_IN_PBL, RCVD_IN_ZEN_BLOCKED_OPENDNS, __RCVD_IN_ZEN, RCVD_IN_ZEN_BLOCKED, RCVD_IN_XBL
2023-04-14T11:22:20.062672-04:00 800-mini-1 spamd[905]: async: aborting after 9.025 s, deadline shrunk: DNSBL, A/127.18.247.158.iadb.isipp.com, rules: __RCVD_IN_IADB
2023-04-14T11:22:20.062734-04:00 800-mini-1 spamd[905]: async: aborting after 9.023 s, deadline shrunk: DNSBL, A/127.18.247.158.wl.mailspike.net, rules: __RCVD_IN_MSPIKE_L
2023-04-14T11:22:20.117186-04:00 800-mini-1 spamd[905]: spamd: clean message (0.0/2.0) for elawson:1000 in 9.1 seconds, 100704 bytes.
2023-04-14T11:22:20.117317-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIMWL_WL_MED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_EF,DMARC_MISSING,HEADER_FROM_DIFFERENT_DOMAINS,HTML_FONT_LOW_CONTRAST,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_SPF_HELO_TEMPERROR,URI_HEX scantime=9.1,size=100704,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=35172,mid=<1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net>,autolearn=ham autolearn_force=no
2023-04-14T11:24:31.576229-04:00 800-mini-1 smartd[629]: Device: /dev/sda [SAT], SMART Usage Attribute: 190 Airflow_Temperature_Cel changed from 63 to 58
2023-04-14T11:24:51.417067-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Activating service name='org.xfce.Xfconf' requested by ':1.17' (uid=1000 pid=1096 comm="xfce4-panel --display :0.0 --sm-client-id 22419696")
2023-04-14T11:24:51.424376-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Successfully activated service 'org.xfce.Xfconf'
2023-04-14T11:30:01.065922-04:00 800-mini-1 CRON[7187]: (root) CMD ([ -x /etc/init.d/anacron ] && if [ ! -d /run/systemd/system ]; then /usr/sbin/invoke-rc.d anacron start >/dev/null; fi)
2023-04-14T11:32:24.523655-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:40140 to port 783, fd 5
2023-04-14T11:32:24.524725-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:32:24.529757-04:00 800-mini-1 spamd[905]: spamd: checking message <a6f85c0f-b23d-41b4...@iad4s12mta7.xt.local> for elawson:1000
2023-04-14T11:32:24.829076-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 42 bytes
2023-04-14T11:32:36.894241-04:00 800-mini-1 spamd[905]: async: aborting after 12.343 s, deadline shrunk: AskDNS, A/gritterohub.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
2023-04-14T11:32:36.894457-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.list.dnswl.org, rules: __RCVD_IN_DNSWL
2023-04-14T11:32:36.894531-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL-Sender, A/bounce.gritterohub.com, rules: NO_DNS_FOR_FROM
2023-04-14T11:32:36.894593-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.mailspike.net, rules: __RCVD_IN_MSPIKE_B
2023-04-14T11:32:36.894656-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.iadb.isipp.com, rules: __RCVD_IN_IADB
2023-04-14T11:32:36.894758-04:00 800-mini-1 spamd[905]: async: aborting after 12.345 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:32:36.894856-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
2023-04-14T11:32:36.894983-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.psbl.surriel.com, rules: RCVD_IN_PSBL
2023-04-14T11:32:36.895079-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
2023-04-14T11:32:36.900670-04:00 800-mini-1 spamd[905]: spamd: clean message (0.3/2.0) for elawson:1000 in 12.4 seconds, 17398 bytes.
2023-04-14T11:32:36.900843-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_MESSAGE,RCVD_IN_BL_SPAMCOP_NET,RCVD_IN_MSPIKE_H2,SUBJ_DOLLARS,T_SPF_HELO_TEMPERROR,T_SPF_PERMERROR scantime=12.4,size=17398,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=40140,mid=<a6f85c0f-b23d-41b4...@iad4s12mta7.xt.local>,autolearn=no autolearn_force=no
2023-04-14T11:34:51.512827-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Activating service name='org.xfce.Xfconf' requested by ':1.17' (uid=1000 pid=1096 comm="xfce4-panel --display :0.0 --sm-client-id 22419696")
* What was the outcome of this action?
* What outcome did you expect instead?
*** End of the template - remove these template lines ***
-- System Information:
Debian Release: 12.0
APT prefers unstable
APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)
Kernel: Linux 6.1.0-7-amd64 (SMP w/4 CPU threads; PREEMPT)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages spamd depends on:
ii init-system-helpers 1.65.2
ii rsyslog [system-log-daemon] 8.2302.0-1
ii spamassassin 4.0.0-4
ii systemd 252.6-1
spamd recommends no packages.
spamd suggests no packages.
-- no debconf information
Version: 4.0.0-4
Severity: important
X-Debbugs-Cc: ela...@grizzy.com
Dear Maintainer,
*** Reporter, please consider answering these questions, where appropriate ***
* What led up to the situation?
AI have run Sid for years and with a few issues had a working
spamfiltering system using spamd and the claws plugin. A few months
ago I noticed that although Claws indicated spamassassin was
filtering the mail, no mail was being filtered and send to the spam
folder. I checked the configuration of Spamassassin and the claws
plug in and nothing seemed to be wrong or different from when the
system performed properly.
the syslog entires suggest something spamd is in fact trying to
work, but for various reasons it aborts. Here are the entires from
syslog.
2023-04-14T11:16:57.933705-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:52922 to port 783, fd 5
2023-04-14T11:16:57.938346-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:16:57.944632-04:00 800-mini-1 spamd[905]: spamd: checking message <eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8> for elawson:1000
2023-04-14T11:17:01.051774-04:00 800-mini-1 CRON[5905]: (root) CMD (cd / && run-parts --report /etc/cron.hourly)
2023-04-14T11:17:08.848257-04:00 800-mini-1 spamd[905]: async: aborting after 10.851 s, deadline shrunk: DNSBL, A/188.100.89.167.psbl.surriel.com, rules: RCVD_IN_PSBL
2023-04-14T11:17:08.848465-04:00 800-mini-1 spamd[905]: async: aborting after 10.853 s, deadline shrunk: DNSBL, A/188.100.89.167.zen.spamhaus.org, rules: RCVD_IN_PBL, __RCVD_IN_ZEN, RCVD_IN_ZEN_BLOCKED_OPENDNS, RCVD_IN_ZEN_BLOCKED, RCVD_IN_XBL
2023-04-14T11:17:08.848535-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, TXT/188.100.89.167.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:17:08.848592-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, TXT/188.100.89.167.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
2023-04-14T11:17:08.848682-04:00 800-mini-1 spamd[905]: async: aborting after 10.848 s, deadline shrunk: AskDNS, A/ebay.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
2023-04-14T11:17:08.848844-04:00 800-mini-1 spamd[905]: async: aborting after 10.852 s, deadline shrunk: DNSBL, A/188.100.89.167.list.dnswl.org, rules: __RCVD_IN_DNSWL
2023-04-14T11:17:08.848984-04:00 800-mini-1 spamd[905]: async: aborting after 10.850 s, deadline shrunk: DNSBL, A/188.100.89.167.dnsbl.sorbs.net, rules: __RCVD_IN_SORBS, RCVD_IN_SORBS_DUL
2023-04-14T11:17:08.912069-04:00 800-mini-1 spamd[905]: spamd: clean message (-17.0/2.0) for elawson:1000 in 11.0 seconds, 97709 bytes.
2023-04-14T11:17:08.912273-04:00 800-mini-1 spamd[905]: spamd: result: . -16 - DKIMWL_WL_HIGH,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_IMAGE_RATIO_08,HTML_MESSAGE,MIME_HTML_ONLY,RCVD_IN_MSPIKE_H2,SPF_PASS,T_KAM_HTML_FONT_INVALID,T_SPF_HELO_TEMPERROR,USER_IN_DEF_DKIM_WL,USER_IN_DEF_SPF_WL scantime=11.0,size=97709,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=52922,mid=<eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8>,autolearn=ham autolearn_force=no
2023-04-14T11:22:10.970820-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:35172 to port 783, fd 5
2023-04-14T11:22:10.974041-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:22:10.980913-04:00 800-mini-1 spamd[905]: spamd: checking message <1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net> for elawson:1000
2023-04-14T11:22:13.554862-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 504 bytes
2023-04-14T11:22:13.575439-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 124 bytes
2023-04-14T11:22:20.062314-04:00 800-mini-1 spamd[905]: async: aborting after 9.023 s, deadline shrunk: DNSBL, TXT/127.18.247.158.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:22:20.062535-04:00 800-mini-1 spamd[905]: async: aborting after 9.022 s, deadline shrunk: DNSBL, A/127.18.247.158.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
2023-04-14T11:22:20.062610-04:00 800-mini-1 spamd[905]: async: aborting after 9.025 s, deadline shrunk: DNSBL, A/127.18.247.158.zen.spamhaus.org, rules: RCVD_IN_PBL, RCVD_IN_ZEN_BLOCKED_OPENDNS, __RCVD_IN_ZEN, RCVD_IN_ZEN_BLOCKED, RCVD_IN_XBL
2023-04-14T11:22:20.062672-04:00 800-mini-1 spamd[905]: async: aborting after 9.025 s, deadline shrunk: DNSBL, A/127.18.247.158.iadb.isipp.com, rules: __RCVD_IN_IADB
2023-04-14T11:22:20.062734-04:00 800-mini-1 spamd[905]: async: aborting after 9.023 s, deadline shrunk: DNSBL, A/127.18.247.158.wl.mailspike.net, rules: __RCVD_IN_MSPIKE_L
2023-04-14T11:22:20.117186-04:00 800-mini-1 spamd[905]: spamd: clean message (0.0/2.0) for elawson:1000 in 9.1 seconds, 100704 bytes.
2023-04-14T11:22:20.117317-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIMWL_WL_MED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_EF,DMARC_MISSING,HEADER_FROM_DIFFERENT_DOMAINS,HTML_FONT_LOW_CONTRAST,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_SPF_HELO_TEMPERROR,URI_HEX scantime=9.1,size=100704,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=35172,mid=<1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net>,autolearn=ham autolearn_force=no
2023-04-14T11:24:31.576229-04:00 800-mini-1 smartd[629]: Device: /dev/sda [SAT], SMART Usage Attribute: 190 Airflow_Temperature_Cel changed from 63 to 58
2023-04-14T11:24:51.417067-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Activating service name='org.xfce.Xfconf' requested by ':1.17' (uid=1000 pid=1096 comm="xfce4-panel --display :0.0 --sm-client-id 22419696")
2023-04-14T11:24:51.424376-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Successfully activated service 'org.xfce.Xfconf'
2023-04-14T11:30:01.065922-04:00 800-mini-1 CRON[7187]: (root) CMD ([ -x /etc/init.d/anacron ] && if [ ! -d /run/systemd/system ]; then /usr/sbin/invoke-rc.d anacron start >/dev/null; fi)
2023-04-14T11:32:24.523655-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:40140 to port 783, fd 5
2023-04-14T11:32:24.524725-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
2023-04-14T11:32:24.529757-04:00 800-mini-1 spamd[905]: spamd: checking message <a6f85c0f-b23d-41b4...@iad4s12mta7.xt.local> for elawson:1000
2023-04-14T11:32:24.829076-04:00 800-mini-1 spamd[905]: dns: bgread: received a 512 bytes packet from 192.168.0.1, decoded 42 bytes
2023-04-14T11:32:36.894241-04:00 800-mini-1 spamd[905]: async: aborting after 12.343 s, deadline shrunk: AskDNS, A/gritterohub.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
2023-04-14T11:32:36.894457-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.list.dnswl.org, rules: __RCVD_IN_DNSWL
2023-04-14T11:32:36.894531-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL-Sender, A/bounce.gritterohub.com, rules: NO_DNS_FOR_FROM
2023-04-14T11:32:36.894593-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.mailspike.net, rules: __RCVD_IN_MSPIKE_B
2023-04-14T11:32:36.894656-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.iadb.isipp.com, rules: __RCVD_IN_IADB
2023-04-14T11:32:36.894758-04:00 800-mini-1 spamd[905]: async: aborting after 12.345 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
2023-04-14T11:32:36.894856-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
2023-04-14T11:32:36.894983-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.psbl.surriel.com, rules: RCVD_IN_PSBL
2023-04-14T11:32:36.895079-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
2023-04-14T11:32:36.900670-04:00 800-mini-1 spamd[905]: spamd: clean message (0.3/2.0) for elawson:1000 in 12.4 seconds, 17398 bytes.
2023-04-14T11:32:36.900843-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_MESSAGE,RCVD_IN_BL_SPAMCOP_NET,RCVD_IN_MSPIKE_H2,SUBJ_DOLLARS,T_SPF_HELO_TEMPERROR,T_SPF_PERMERROR scantime=12.4,size=17398,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=40140,mid=<a6f85c0f-b23d-41b4...@iad4s12mta7.xt.local>,autolearn=no autolearn_force=no
2023-04-14T11:34:51.512827-04:00 800-mini-1 dbus-daemon[968]: [session uid=1000 pid=968] Activating service name='org.xfce.Xfconf' requested by ':1.17' (uid=1000 pid=1096 comm="xfce4-panel --display :0.0 --sm-client-id 22419696")
* What was the outcome of this action?
* What outcome did you expect instead?
*** End of the template - remove these template lines ***
-- System Information:
Debian Release: 12.0
APT prefers unstable
APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)
Kernel: Linux 6.1.0-7-amd64 (SMP w/4 CPU threads; PREEMPT)
Locale: LANG=en_US.UTF-8, LC_CTYPE=en_US.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled
Versions of packages spamd depends on:
ii init-system-helpers 1.65.2
ii rsyslog [system-log-daemon] 8.2302.0-1
ii spamassassin 4.0.0-4
ii systemd 252.6-1
spamd recommends no packages.
spamd suggests no packages.
-- no debconf information
Noah Meyerhans
Apr 15, 2023, 12:00:04 AM4/15/23
to
Control: tags -1 + moreinfo
On Fri, Apr 14, 2023 at 08:29:10PM -0400, Ed Lawson wrote:
> * What led up to the situation?
> AI have run Sid for years and with a few issues had a working
> spamfiltering system using spamd and the claws plugin. A few months
> ago I noticed that although Claws indicated spamassassin was
> filtering the mail, no mail was being filtered and send to the spam
> folder. I checked the configuration of Spamassassin and the claws
> plug in and nothing seemed to be wrong or different from when the
> system performed properly.
>
> the syslog entires suggest something spamd is in fact trying to
> work, but for various reasons it aborts. Here are the entires from
> syslog.
There are a number of DNS aborts logged, but those can happen for
various reasons. They all seem to involve looking up entries in various
DNS-accessible databases, and network policies, transient network
issues, or just high latency can all lead to this sort of situation.
> 2023-04-14T11:17:08.912273-04:00 800-mini-1 spamd[905]: spamd: result: . -16 - DKIMWL_WL_HIGH,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_IMAGE_RATIO_08,HTML_MESSAGE,MIME_HTML_ONLY,RCVD_IN_MSPIKE_H2,SPF_PASS,T_KAM_HTML_FONT_INVALID,T_SPF_HELO_TEMPERROR,USER_IN_DEF_DKIM_WL,USER_IN_DEF_SPF_WL scantime=11.0,size=97709,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=52922,mid=<eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8>,autolearn=ham autolearn_force=no
This message indicates that spamd has completed processing of this
message and given it a negative spam score for various reasons.
> 2023-04-14T11:22:10.970820-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:35172 to port 783, fd 5
> 2023-04-14T11:22:10.974041-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
> 2023-04-14T11:22:10.980913-04:00 800-mini-1 spamd[905]: spamd: checking message <1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net> for elawson:1000
...
is working in general.
> 2023-04-14T11:32:36.894241-04:00 800-mini-1 spamd[905]: async: aborting after 12.343 s, deadline shrunk: AskDNS, A/gritterohub.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
> 2023-04-14T11:32:36.894457-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.list.dnswl.org, rules: __RCVD_IN_DNSWL
> 2023-04-14T11:32:36.894531-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL-Sender, A/bounce.gritterohub.com, rules: NO_DNS_FOR_FROM
> 2023-04-14T11:32:36.894593-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.mailspike.net, rules: __RCVD_IN_MSPIKE_B
> 2023-04-14T11:32:36.894656-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.iadb.isipp.com, rules: __RCVD_IN_IADB
> 2023-04-14T11:32:36.894758-04:00 800-mini-1 spamd[905]: async: aborting after 12.345 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
> 2023-04-14T11:32:36.894856-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
> 2023-04-14T11:32:36.894983-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.psbl.surriel.com, rules: RCVD_IN_PSBL
> 2023-04-14T11:32:36.895079-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
> 2023-04-14T11:32:36.900670-04:00 800-mini-1 spamd[905]: spamd: clean message (0.3/2.0) for elawson:1000 in 12.4 seconds, 17398 bytes.
These all indicate timeouts waiting for responses from some internet
resource. The time indicated is well over 12s in each case, which
certainly seems like a sufficient amount of time to wait before giving
up.
I think you'll want to investigate connectivity to these various
services, or if that doesn't seem to lead anywhere, simply turn them
off. If the query replies are never actually getting back to spamd,
there's not much it can do about that.
noah
On Fri, Apr 14, 2023 at 08:29:10PM -0400, Ed Lawson wrote:
> * What led up to the situation?
> AI have run Sid for years and with a few issues had a working
> spamfiltering system using spamd and the claws plugin. A few months
> ago I noticed that although Claws indicated spamassassin was
> filtering the mail, no mail was being filtered and send to the spam
> folder. I checked the configuration of Spamassassin and the claws
> plug in and nothing seemed to be wrong or different from when the
> system performed properly.
>
> the syslog entires suggest something spamd is in fact trying to
> work, but for various reasons it aborts. Here are the entires from
> syslog.
various reasons. They all seem to involve looking up entries in various
DNS-accessible databases, and network policies, transient network
issues, or just high latency can all lead to this sort of situation.
> 2023-04-14T11:17:08.912273-04:00 800-mini-1 spamd[905]: spamd: result: . -16 - DKIMWL_WL_HIGH,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DMARC_PASS,HTML_IMAGE_RATIO_08,HTML_MESSAGE,MIME_HTML_ONLY,RCVD_IN_MSPIKE_H2,SPF_PASS,T_KAM_HTML_FONT_INVALID,T_SPF_HELO_TEMPERROR,USER_IN_DEF_DKIM_WL,USER_IN_DEF_SPF_WL scantime=11.0,size=97709,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=52922,mid=<eETCwAhORcqoR4vQoyLr-A@geopod-ismtpd-8>,autolearn=ham autolearn_force=no
message and given it a negative spam score for various reasons.
> 2023-04-14T11:22:10.970820-04:00 800-mini-1 spamd[905]: spamd: connection from localhost [::1]:35172 to port 783, fd 5
> 2023-04-14T11:22:10.974041-04:00 800-mini-1 spamd[905]: spamd: setuid to elawson succeeded
> 2023-04-14T11:22:10.980913-04:00 800-mini-1 spamd[905]: spamd: checking message <1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net> for elawson:1000
> 2023-04-14T11:22:20.117186-04:00 800-mini-1 spamd[905]: spamd: clean message (0.0/2.0) for elawson:1000 in 9.1 seconds, 100704 bytes.
> 2023-04-14T11:22:20.117317-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIMWL_WL_MED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_EF,DMARC_MISSING,HEADER_FROM_DIFFERENT_DOMAINS,HTML_FONT_LOW_CONTRAST,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_SPF_HELO_TEMPERROR,URI_HEX scantime=9.1,size=100704,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=35172,mid=<1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net>,autolearn=ham autolearn_force=no
This also shows a successful message processing. So it looks like spamd
> 2023-04-14T11:22:20.117317-04:00 800-mini-1 spamd[905]: spamd: result: . 0 - DKIMWL_WL_MED,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_EF,DMARC_MISSING,HEADER_FROM_DIFFERENT_DOMAINS,HTML_FONT_LOW_CONTRAST,HTML_MESSAGE,RCVD_IN_DNSWL_NONE,SPF_PASS,T_SPF_HELO_TEMPERROR,URI_HEX scantime=9.1,size=100704,user=elawson,uid=1000,required_score=2.0,rhost=localhost,raddr=::1,rport=35172,mid=<1681485329874.b956b8ec-4b...@bf02x.hubspotemail.net>,autolearn=ham autolearn_force=no
is working in general.
> 2023-04-14T11:32:36.894241-04:00 800-mini-1 spamd[905]: async: aborting after 12.343 s, deadline shrunk: AskDNS, A/gritterohub.com.fresh.fmb.la, rules: __FROM_FMBLA_NDBLOCKED, __FROM_FMBLA_NEWDOM14, __FROM_FMBLA_NEWDOM, __FROM_FMBLA_NEWDOM28
> 2023-04-14T11:32:36.894457-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.list.dnswl.org, rules: __RCVD_IN_DNSWL
> 2023-04-14T11:32:36.894531-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL-Sender, A/bounce.gritterohub.com, rules: NO_DNS_FOR_FROM
> 2023-04-14T11:32:36.894593-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.mailspike.net, rules: __RCVD_IN_MSPIKE_B
> 2023-04-14T11:32:36.894656-04:00 800-mini-1 spamd[905]: async: aborting after 12.347 s, deadline shrunk: DNSBL, A/14.209.110.13.iadb.isipp.com, rules: __RCVD_IN_IADB
> 2023-04-14T11:32:36.894758-04:00 800-mini-1 spamd[905]: async: aborting after 12.345 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-trusted.bondedsender.org, rules: RCVD_IN_VALIDITY_CERTIFIED
> 2023-04-14T11:32:36.894856-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, TXT/14.209.110.13.sa-accredit.habeas.com, rules: RCVD_IN_VALIDITY_SAFE
> 2023-04-14T11:32:36.894983-04:00 800-mini-1 spamd[905]: async: aborting after 12.346 s, deadline shrunk: DNSBL, A/14.209.110.13.psbl.surriel.com, rules: RCVD_IN_PSBL
> 2023-04-14T11:32:36.895079-04:00 800-mini-1 spamd[905]: async: aborting after 12.344 s, deadline shrunk: DNSBL, A/14.209.110.13.bl.score.senderscore.com, rules: RCVD_IN_VALIDITY_RPBL
> 2023-04-14T11:32:36.900670-04:00 800-mini-1 spamd[905]: spamd: clean message (0.3/2.0) for elawson:1000 in 12.4 seconds, 17398 bytes.
resource. The time indicated is well over 12s in each case, which
certainly seems like a sufficient amount of time to wait before giving
up.
I think you'll want to investigate connectivity to these various
services, or if that doesn't seem to lead anywhere, simply turn them
off. If the query replies are never actually getting back to spamd,
there's not much it can do about that.
noah
Noah Meyerhans
Apr 16, 2023, 12:30:04 PM4/16/23
to
On Sat, Apr 15, 2023 at 03:56:02AM -0400, Ed Lawson wrote:
> 23-04-13T16:2056:26.075987-04:00 800-mini-1 spamd[938]: spamd: connection from localhost [::1]:44842 to port 783, fd 5
> 2023-04-13T16:56:26.077471-04:00 800-mini-1 spamd[938]: spamd: setuid to elawson succeeded
> 2023-04-13T16:56:26.089459-04:00 800-mini-1 spamd[938]: spamd: checking message <bounce--iaim...@send.smartbrief.com> for elawson:1000
> 2023-04-13T16:56:26.135987-04:00 800-mini-1 spamd[938]: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53
> 2023-04-13T16:56:26.137769-04:00 800-mini-1 spamd[938]: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53
These don't necessarily indicated an inability to filter messages, but
they are indicating an inability to talk to the DNS resolver on
localhost with either IPv4 or IPv6. Is that the DNS server you expect
spamassassin to be using? What's in `/etc/resolv.conf`?
The symptoms seem similar to those reported in
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1034347
noah
> 23-04-13T16:2056:26.075987-04:00 800-mini-1 spamd[938]: spamd: connection from localhost [::1]:44842 to port 783, fd 5
> 2023-04-13T16:56:26.077471-04:00 800-mini-1 spamd[938]: spamd: setuid to elawson succeeded
> 2023-04-13T16:56:26.089459-04:00 800-mini-1 spamd[938]: spamd: checking message <bounce--iaim...@send.smartbrief.com> for elawson:1000
> 2023-04-13T16:56:26.135987-04:00 800-mini-1 spamd[938]: dns: sendto() to [127.0.0.1]:53 failed: Connection refused, failing over to [::1]:53
> 2023-04-13T16:56:26.137769-04:00 800-mini-1 spamd[938]: dns: sendto() to [::1]:53 failed: Connection refused, failing over to [127.0.0.1]:53
These don't necessarily indicated an inability to filter messages, but
they are indicating an inability to talk to the DNS resolver on
localhost with either IPv4 or IPv6. Is that the DNS server you expect
spamassassin to be using? What's in `/etc/resolv.conf`?
The symptoms seem similar to those reported in
https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1034347
noah
0 new messages