Mailing List Archive

Log reporting spamd[11912]: dns: [...] messages
SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
Postfix 2.10.1
unbound 1.6.6


Expanded defences to include dnswl.
Recommendation to install local dns caching server followed.
Once installed, large numbers of messages started to appear in maillog.

Intended to only access the one white-list service. Have I accidentally
released a hydra of services/checks?

Is there a way to reduce all of these log-lines?
(many times longer than the actual email message itself)


Apologies for first-post, learner, ignorance. Web-searching has not
revealed the secret. Will appreciate pointers to relevant docs!


Here is an example interaction from maillog:-

NB outbound message from one of server's domains to two recipients on
two separate domains.


May 28 22:12:54 vps517507 postfix/smtpd[22251]: Anonymous TLS connection
established from 118-92-199-252.dsl.dyn.ihug.co.nz[118.92.199.252]:
TLSv1.2 with cipher ECDHE-ECDSA-AES256-GCM-SHA384 (256/256 bits)
May 28 22:12:55 vps517507 postfix/smtpd[22251]: DAE2B6AAE:
client=118-92-199-252.dsl.dyn.ihug.co.nz[118.92.199.252],
sasl_method=PLAIN, sasl_username=domainadmin@rangi.cloud
May 28 22:12:57 vps517507 postfix/cleanup[22259]: DAE2B6AAE:
message-id=<ac8ddad5-8516-162e-cb7e-a4eb7bf077b5@etelligence.info>
May 28 22:12:57 vps517507 opendkim[16791]: DAE2B6AAE: DKIM-Signature
field added (s=staff, d=etelligence.info)
May 28 22:12:57 vps517507 postfix/qmgr[22236]: DAE2B6AAE:
from=<NZPUG@etelligence.info>, size=17034, nrcpt=2 (queue active)
May 28 22:12:57 vps517507 spamd[11912]: spamd: connection from localhost
[::1]:49920 to port 783, fd 6
May 28 22:12:57 vps517507 spamd[11912]: spamd: setuid to spamd succeeded
May 28 22:12:57 vps517507 spamd[11913]: spamd: connection from localhost
[::1]:49922 to port 783, fd 6
May 28 22:12:57 vps517507 spamd[11912]: spamd: processing message
<ac8ddad5-8516-162e-cb7e-a4eb7bf077b5@etelligence.info> for spamd:2001
May 28 22:12:57 vps517507 spamd[11913]: spamd: setuid to spamd succeeded
May 28 22:12:57 vps517507 spamd[11913]: spamd: processing message
<ac8ddad5-8516-162e-cb7e-a4eb7bf077b5@etelligence.info> for spamd:2001
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
31575/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; HEADER SECTION

* followed by a series of messages reminiscent of dig output

May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; HEADER SECTION
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; id = 31575
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; qr = 1 aa = 0 tc =
0 rd = 0 opcode = QUERY
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; ra = 0 z = 0 ad =
0 cd = 0 rcode = REFUSED
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; qdcount = 0
ancount = 0 nscount = 0 arcount = 0
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; do = 0
May 28 22:12:57 vps517507 spamd[11912]: dns: [...]
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; QUESTION SECTION
(0 records)
May 28 22:12:57 vps517507 spamd[11912]: dns: [...]
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; ANSWER SECTION (0
records)
May 28 22:12:57 vps517507 spamd[11912]: dns: [...]
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; AUTHORITY SECTION
(0 records)
May 28 22:12:57 vps517507 spamd[11912]: dns: [...]
May 28 22:12:57 vps517507 spamd[11912]: dns: [...] ;; ADDITIONAL SECTION
(0 records)May 28 22:12:57 vps517507 spamd[11912]: dns: a likely
matching query: 31575/IN/A/etelligence.info.multi.uribl.com
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
48855/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

* rinse and repeat with id = 48855, then id 2327, then id 46114
When reaches id of 16631, report changes to NS record:

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
16631/IN/NS/etelligence.info
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
45958/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

* but carries on with id = 45958, which reports:

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
45958/IN/A/etelligence.info
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
2089/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

* which hands-over to id = 2089, which reports differently:

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
2089/IN/A/twl06.py.multi.uribl.com
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
8583/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

* the game continues with id = 8583 reporting the same as above. Then,
id = 10302, produces:

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
10302/IN/A/twl06.py.dob.sibl.support-intelligence.net
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
37129/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

* and id = 37129:

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
37129/IN/A/twl06.py.dbl.spamhaus.org
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
52352/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
52352/IN/NS/twl06.py
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
43281/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
43281/IN/A/twl06.py
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
33346/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
33346/IN/MX/etelligence.info
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
63084/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
63084/IN/A/etelligence.info.multi.surbl.org
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
27888/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
27888/IN/A/etelligence.info.multi.uribl.com
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
38041/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
38041/IN/A/etelligence.info.dob.sibl.support-intelligence.net
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
62928/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
62928/IN/A/etelligence.info.dbl.spamhaus.org
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
6720/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
6720/IN/NS/etelligence.info
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
25105/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
25105/IN/A/etelligence.info
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
39380/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
39380/IN/A/twl06.py.multi.surbl.org
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
59823/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
59823/IN/A/twl06.py.multi.uribl.com
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
22095/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
22095/IN/A/twl06.py.dob.sibl.support-intelligence.net
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
28493/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
28493/IN/A/twl06.py.dbl.spamhaus.org
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
8203/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
8203/IN/NS/twl06.py
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
23333/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
23333/IN/A/twl06.py
May 28 22:12:57 vps517507 spamd[11913]: dns: no callback for id
33861/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11913]: dns: a likely matching query:
33861/IN/MX/etelligence.info
May 28 22:12:57 vps517507 postfix/smtpd[22251]: disconnect from
118-92-199-252.dsl.dyn.ihug.co.nz[118.92.199.252] ehlo=2 starttls=1
auth=1 mail=1 rcpt=2 data=1 quit=1 commands=9
May 28 22:12:57 vps517507 spamd[11912]: dns: no callback for id
49279/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:57 vps517507 spamd[11912]: dns: a likely matching query:
49279/IN/A/etelligence.info.lookup.dkimwl.org
May 28 22:12:59 vps517507 spamd[11913]: dns: no callback for id
46685/NO_QUESTION_IN_PACKET, ignored; packet: ;; Answer received from
127.0.0.1 (12 bytes)

...

May 28 22:12:59 vps517507 spamd[11913]: dns: a likely matching query:
46685/IN/A/etelligence.info.lookup.dkimwl.org

* and finally, the message is 'approved' for transmission:

May 28 22:13:12 vps517507 spamd[11913]: spamd: clean message (-5.2/5.0)
for spamd:2001 in 15.9 seconds, 17271 bytes.
May 28 22:13:12 vps517507 spamd[11913]: spamd: result: . -5 -
ALL_TRUSTED,BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,NICE_REPLY_A,T_SCC_BODY_TEXT_LINE
scantime=15.9,size=17271,user=spamd,uid=2001,required_score=5.0,rhost=localhost,raddr=::1,rport=49922,mid=<ac8ddad5-8516-162e-cb7e-a4eb7bf077b5@etelligence.info>,bayes=0.000000,autolearn=ham
autolearn_force=no
May 28 22:13:13 vps517507 postfix/pipe[22261]: DAE2B6AAE:
to=<nathan-tech@hotmail.com>, relay=spamassassin, delay=17,
delays=1.5/0.03/0/16, dsn=2.0.0, status=sent (delivered via spamassassin
service)



--
Regards,
=dn
Re: Log reporting spamd[11912]: dns: [...] messages [ In reply to ]
DL Neil:
> SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
> Postfix 2.10.1
> unbound 1.6.6

This does not answer your question, but I noticed that the versions you
gave are all ~5–8 years old. Often enough such problems disappear after
upgrading to a current version.
Re: Log reporting spamd[11912]: dns: [...] messages [ In reply to ]
On 2022-05-29 01:25, DL Neil wrote:
> SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
> Postfix 2.10.1
> unbound 1.6.6

upgrade centos

and check you dont added -D or --debug into spamd options

more help show spamd options
Re: Log reporting spamd[11912]: dns: [...] messages [ In reply to ]
On 2022-05-28 at 19:25:46 UTC-0400 (Sun, 29 May 2022 11:25:46 +1200)
DL Neil <SAlist@Rangi.Cloud>
is rumored to have said:

> SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
> Postfix 2.10.1
> unbound 1.6.6

Obsolete antiques all...

> Expanded defences to include dnswl.
> Recommendation to install local dns caching server followed.
> Once installed, large numbers of messages started to appear in
> maillog.

The messages you included indicate that you've got spamd running with
debug enabled. The usual way to set debugging is in
/etc/sysconfig/spamassassin with the 'SPAMDOPTIONS' parameter. The
option to remove is '-D' and any list of message types that follow it.

I have no idea how you could have gotten the debug option enabled
without knowing it.

> Intended to only access the one white-list service. Have I
> accidentally
> released a hydra of services/checks?

I guess that's a matter of definition...

The spamd daemon is one service, listening either on a unix-domain
socket or a TCP port, usually port 783. The parent spamd process handles
the listener and spawns a small number of child processes to which it
distributes individual messages for scanning.

SpamAssassin does a substantial number of DNS lookups to check the
domains used in email addresses and URLs in the message. The number of
these is dependent on your local configuration, but there are many
enabled by default.

> Is there a way to reduce all of these log-lines?
> (many times longer than the actual email message itself)

Switch off debug logging, and the messages will stop.


--
Bill Cole
bill@scconsult.com or billcole@apache.org
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Not Currently Available For Hire
Re: Log reporting spamd[11912]: dns: [...] messages [ In reply to ]
On 30/05/2022 03.06, Bill Cole wrote:
> On 2022-05-28 at 19:25:46 UTC-0400 (Sun, 29 May 2022 11:25:46 +1200)
> DL Neil <SAlist@Rangi.Cloud>
> is rumored to have said:

No, he said it.


>> SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
>> Postfix 2.10.1
>> unbound 1.6.6
>
> Obsolete antiques all...

May be so, but some (would) like stability, aka trying to get it right
before making it better*

* being whatever settle on using to replace CentOS...

- but thank you for the warning/reminder!


>> Expanded defences to include dnswl.
>> Recommendation to install local dns caching server followed.
>> Once installed, large numbers of messages started to appear in maillog.
>
> The messages you included indicate that you've got spamd running with
> debug enabled. The usual way to set debugging is in
> /etc/sysconfig/spamassassin with the 'SPAMDOPTIONS' parameter. The
> option to remove is '-D' and any list of message types that follow it.

That was my first thought

NB word of caution to all who instantly-believe SO and similar advice:
reading the docs to understand what is being said, showed that -D and -d
are quite different, and thus not a 'typo'!


> I have no idea how you could have gotten the debug option enabled
> without knowing it.

Nor I, but ...


>> Intended to only access the one white-list service. Have I accidentally
>> released a hydra of services/checks?
>
> I guess that's a matter of definition...
>
> The spamd daemon is one service, listening either on a unix-domain
> socket or a TCP port, usually port 783. The parent spamd process handles
> the listener and spawns a small number of child processes to which it
> distributes individual messages for scanning.
>
> SpamAssassin does a substantial number of DNS lookups to check the
> domains used in email addresses and URLs in the message. The number of
> these is dependent on your local configuration, but there are many
> enabled by default.
>
>> Is there a way to reduce all of these log-lines?
>> (many times longer than the actual email message itself)
>
> Switch off debug logging, and the messages will stop.

I don't think it's on - having spent hours trying to find decent docs
which would tell me each of the different ways such might happen.

I did edit the /etc/sysconfig/spamassassin file. Herewith what systemctl
does with it (and showing that the environment variable holds no value):

vps517507 /etc/mail/spamassassin: systemctl status spamassassin
? spamassassin.service - Spamassassin daemon
Loaded: loaded (/usr/lib/systemd/system/spamassassin.service;
enabled; vendor preset: disabled)
Active: active (running) since Mon 2022-05-30 00:01:55 UTC; 11s ago
Process: 4912 ExecStart=/usr/bin/spamd --pidfile /var/run/spamd.pid
$SPAMDOPTIONS (code=exited, status=0/SUCCESS)
Process: 4910 ExecStartPre=/sbin/portrelease spamd (code=exited,
status=0/SUCCESS)
Main PID: 4917 (/usr/bin/spamd )
CGroup: /system.slice/spamassassin.service
??4917 /usr/bin/spamd --pidfile /var/run/spamd.pid -d -m5
??4919 spamd child
??4920 spamd child
...

vps517507 /etc/mail/spamassassin: echo $SPAMDOPTIONS


vps517507 /etc/mail/spamassassin:
--
Regards =dn
Re: Log reporting spamd[11912]: dns: [...] messages [ In reply to ]
On 2022-05-30 at 06:22:39 UTC-0400 (Mon, 30 May 2022 22:22:39 +1200)
DL Neil <SAlist@rangi.cloud>
is rumored to have said:

> On 30/05/2022 03.06, Bill Cole wrote:
>> On 2022-05-28 at 19:25:46 UTC-0400 (Sun, 29 May 2022 11:25:46 +1200)
>> DL Neil <SAlist@Rangi.Cloud>
>> is rumored to have said:
>
> No, he said it.
>
>
>>> SpamAssassin x86_64 3.4.0 CentOS 6.el7 release
>>> Postfix 2.10.1
>>> unbound 1.6.6
>>
>> Obsolete antiques all...
>
> May be so, but some (would) like stability, aka trying to get it right
> before making it better*
>
> * being whatever settle on using to replace CentOS...
>
> - but thank you for the warning/reminder!
>
>
>>> Expanded defences to include dnswl.
>>> Recommendation to install local dns caching server followed.
>>> Once installed, large numbers of messages started to appear in
>>> maillog.
>>
>> The messages you included indicate that you've got spamd running with
>> debug enabled. The usual way to set debugging is in
>> /etc/sysconfig/spamassassin with the 'SPAMDOPTIONS' parameter. The
>> option to remove is '-D' and any list of message types that follow
>> it.
>
> That was my first thought
>
> NB word of caution to all who instantly-believe SO and similar advice:
> reading the docs to understand what is being said, showed that -D and
> -d
> are quite different, and thus not a 'typo'!
>
>
>> I have no idea how you could have gotten the debug option enabled
>> without knowing it.
>
> Nor I, but ...
>
>
>>> Intended to only access the one white-list service. Have I
>>> accidentally
>>> released a hydra of services/checks?
>>
>> I guess that's a matter of definition...
>>
>> The spamd daemon is one service, listening either on a unix-domain
>> socket or a TCP port, usually port 783. The parent spamd process
>> handles
>> the listener and spawns a small number of child processes to which it
>> distributes individual messages for scanning.
>>
>> SpamAssassin does a substantial number of DNS lookups to check the
>> domains used in email addresses and URLs in the message. The number
>> of
>> these is dependent on your local configuration, but there are many
>> enabled by default.
>>
>>> Is there a way to reduce all of these log-lines?
>>> (many times longer than the actual email message itself)
>>
>> Switch off debug logging, and the messages will stop.
>
> I don't think it's on

It absolutely is. There's no other way to make spamd emit those
messages. It's not magic, it's code. The mystery is: what is turning it
on?

> - having spent hours trying to find decent docs
> which would tell me each of the different ways such might happen.
>
> I did edit the /etc/sysconfig/spamassassin file.

What does it contain?

> Herewith what systemctl
> does with it (and showing that the environment variable holds no
> value):
>
> vps517507 /etc/mail/spamassassin: systemctl status spamassassin
> ? spamassassin.service - Spamassassin daemon
> Loaded: loaded (/usr/lib/systemd/system/spamassassin.service;
> enabled; vendor preset: disabled)
> Active: active (running) since Mon 2022-05-30 00:01:55 UTC; 11s ago
> Process: 4912 ExecStart=/usr/bin/spamd --pidfile /var/run/spamd.pid
> $SPAMDOPTIONS (code=exited, status=0/SUCCESS)
> Process: 4910 ExecStartPre=/sbin/portrelease spamd (code=exited,
> status=0/SUCCESS)
> Main PID: 4917 (/usr/bin/spamd )
> CGroup: /system.slice/spamassassin.service
> ??4917 /usr/bin/spamd --pidfile /var/run/spamd.pid -d
> -m5
> ??4919 spamd child
> ??4920 spamd child
> ...
>
> vps517507 /etc/mail/spamassassin: echo $SPAMDOPTIONS

All that 'echo' shows is what's in your current shell's environment. You
current shell almost certainly didn't load /etc/sysconfig/spamassassin
when launched.

What matters is what SPAMDOPTIONS was in the environment used by
systemctl when it launched spamd. Above, it appears to have been '-d
-m5' but that could possibly be a consequence of how systemctl trims
lines.



--
Bill Cole
bill@scconsult.com or billcole@apache.org
(AKA @grumpybozo and many *@billmail.scconsult.com addresses)
Not Currently Available For Hire