oops, forgot to reply-all (and miss m...@opesmtpd.org), send again ->
> On 07 Apr 2016, at 11:30, Joerg Jung <m...@umaxx.net> wrote:
>
>
>> On 07 Apr 2016, at 10:17, Michiel van Es <m...@pragmasec.nl> wrote:
>>
>>>
>>> On 07 Apr 2016, at 10:02, Joerg Jung <m...@umaxx.net> wrote:
>>>
>>>
>>>> On 07 Apr 2016, at 08:47, Michiel van Es <m...@pragmasec.nl> wrote:
>>>>> On 07 Apr 2016, at 08:41, Joerg Jung <m...@umaxx.net> wrote:
>>>>>
>>>>>>> What asr version have you installed? Recent one?
>>>>>>>
>>>>>>> You can also do a tcpdump please, to see what
>>>>>>> exactly goes over the wire (and comes back)?
>>>>>>>
>>>>>>> Also please temporarily disable all other filters, to
>>>>>>> rule-out chain problems.
>>>>>>
>>>>>> I installed libasr, opensmtpd and OpenSMTPD-Extras from github to ensure
>>>>>> the latest version.
>>>>>>
>>>>>> I use the following config to only use dnsbl:
>>>>>>
>>>>>> filter dnsbl dnsbl "-h" "psbl.surriel.com"
>>>>>> filter filter-clamav clamav
>>>>>> filter all chain dnsbl
>>>>>> filter sub chain filter-clamav
>>>>>> pki server.pragmasec.nl key
>>>>>> "/etc/letsencrypt/archive/server.pragmasec.nl/privkey1.pem"
>>>>>> pki server.pragmasec.nl certificate
>>>>>> "/etc/letsencrypt/archive/server.pragmasec.nl/fullchain1.pem"
>>>>>> listen on lo
>>>>>> listen on ens3 port 25 filter all hostname server.pragmasec.nl tls pki
>>>>>> server.pragmasec.nl
>>>>>> listen on ens3 port 587 filter sub hostname server.pragmasec.nl
>>>>>> tls-require pki server.pragmasec.nl auth mask-source
>>>>>> expire 7d
>>>>>> table vdomains "/usr/local/etc/vdomains"
>>>>>> table vusers "/usr/local/etc/vusers"
>>>>>> accept from any for domain <vdomains> virtual <vusers> deliver to mda
>>>>>> "/usr/lib/dovecot/dovecot-lda -f %{sender} -a %{rcpt}"
>>>>>> accept from local for any relay
>>>>>>
>>>>>> tcpdump of any traffic to psbl.surriel.org: (this seems useless as the
>>>>>> traffic is only dns and goes to the forwarders via my dnsmasq local
>>>>>> cache)
>>>>>> tcpdump -i any | grep ’74.92.59.67'
>>>>>>
>>>>>> *nothing*
>>>>>>
>>>>>> the error with strace and running with smtpd -d -v -T filter:
>>>>>>
>>>>>> epoll_wait(3, debug: smtp: new client on listener: 0x79d0c0
>>>>>> smtp-in: New session 71768b23cba98cf7 from host
>>>>>> pro-mail-smtp-001.bol.com [185.14.168.222]
>>>>>> filter: post-event event=EVENT_CONNECT filter=dnsbl
>>>>>> filter: new query QUERY_CONNECT
>>>>>> filter: filter_drain_query 71768b247df9084f[QUERY_CONNECT=178.21.114.197
>>>>>> <->
>>>>>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x795bc0[datalen=0,eom=(nil),ofile=(nil)]]
>>>>>> filter: running filter filter:dnsbl[hooks=0xffffffff,flags=0x0000] for
>>>>>> query 71768b247df9084f[QUERY_CONNECT=178.21.114.197 <->
>>>>>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x795bc0[datalen=0,eom=(nil),ofile=(nil)]]
>>>>>> filter: waiting for running query
>>>>>> 71768b247df9084f[QUERY_CONNECT=178.21.114.197 <->
>>>>>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x795bc0[datalen=0,eom=(nil),ofile=(nil)]]
>>>>>> dnsbl[22353]: debug: on_connect: checking
>>>>>> 222.168.14.185.psbl.surriel.com.
>>>>>> dnsbl[22353]: warn: session 71768b23cba98cf7: event_dispatch: REJECT
>>>>>> address
>>>>>> filter: imsg IMSG_FILTER_RESPONSE from procfilter
>>>>>> dnsbl[hooks=0xffffffff,flags=0x0000]
>>>>>> filter: filter_drain_query 71768b247df9084f[QUERY_CONNECT=178.21.114.197
>>>>>> <->
>>>>>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x795bc0[datalen=0,eom=(nil),ofile=(nil)]]
>>>>>> filter: filter_end_query 71768b247df9084f[QUERY_CONNECT=178.21.114.197
>>>>>> <->
>>>>>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x795bc0[datalen=0,eom=(nil),ofile=(nil)]]
>>>>>> filter: query 71768b247df9084f done: status=FILTER_CLOSE code=554
>>>>>> response="5.7.1 Address in DNSBL"
>>>>>> smtp-in: Failed command on session 71768b23cba98cf7: "" => 554 5.7.1
>>>>>> Address in DNSBL
>>>>>> smtp-in: Closing session 71768b23cba98cf7
>>>>>> debug: smtp: 0x859c80: deleting session: done
>>>>>> filter: post-event event=EVENT_DISCONNECT filter=dnsbl
>>>>>>
>>>>>> dnsmasq logging:
>>>>>>
>>>>>> Apr 7 07:48:41 server dnsmasq[6018]: query[A]
>>>>>> 222.168.14.185.psbl.surriel.com from 127.0.0.1
>>>>>> Apr 7 07:48:41 server dnsmasq[6018]: forwarded
>>>>>> 222.168.14.185.psbl.surriel.com to 95.85.9.86
>>>>>> Apr 7 07:48:41 server dnsmasq[6018]: reply
>>>>>> 222.168.14.185.psbl.surriel.com is NXDOMAIN
>>>>>>
>>>>>> any more pointers what could go wrong?
>>>>>
>>>>> To me, this really looks like a bug/problem in libasr now (Ubuntu
>>>>> specific).
>>>>
>>>> The libasr is from github (I tried 14.04 and 16.04) but can try a
>>>> different distro to check if others also have this issue?
>>>
>>> Others, e.g. FreeBSD and OpenBSD and some Linux (Debian/Alpine?) are known
>>> to work.
>>> For example, I use filter-dnsbl in production on OpenBSD.
>>
>> Hmm Ubuntu should be a derivative from Debian but I can also try that oner
>> later on.
>> BSD’s are not an option yet because of docker I am using for some containers
>> (I do see the FreeBSD docker option, might try that later ;) )
>>
>>>
>>>>> Despite the NXDOMAIN reply, this condition seems to become true for you:
>>>>> https://github.com/OpenSMTPD/OpenSMTPD-extras/blob/master/extras/wip/filters/filter-dnsbl/filter_dnsbl.c#L44
>>>>>
>>>>> The question is why does it become true und what is the value of:
>>>>> ar->ar_gai_errno (and why has it this value).
>>>>> Can you add/print the value to the log line please? For example:
>>>>> log_warnx("warn: session %016"PRIx64": event_dispatch: REJECT address
>>>>> ar_gai_errno=%d", *q, ar->ar_gai_errno);
>>>>
>>>> where do I need to add it? in which file? to
>>>> /extras/wip/filters/filter-dnsbl/filter_dnsbl.c and recompile the
>>>> OpenSMTPD-Extras?
>>>
>>> Yes, the log_warnx() from line 45 in filter_dnsbl.c
>>> https://github.com/OpenSMTPD/OpenSMTPD-extras/blob/master/extras/wip/filters/filter-dnsbl/filter_dnsbl.c#L45
>>>
>>> Just add ar->ar_gai_errno as additional argument like this:
>>> log_warnx("warn: session %016"PRIx64": event_dispatch: REJECT address
>>> ar_gai_errno=%d", *q, ar->ar_gai_errno);
>>>
>>> ...recompile and see log for the errno value. I hope this gives some
>>> insight (at least is a start).
>>
>> Did that, restart smtpd and got the following:
>>
>> debug: smtp: new client on listener: 0x9b40f0
>> smtp-in: New session 668445e741ecfaa7 from host
>> pro-mail-smtp-001.bol.com[185.14.168.222]
>> filter: post-event event=EVENT_CONNECT filter=dnsbl
>> filter: new query QUERY_CONNECT
>> filter: filter_drain_query 668445e8da5533e5[QUERY_CONNECT=178.21.114.197 <->
>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x9acbf0[datalen=0,eom=(nil),ofile=(nil)]]
>> filter: running filter filter:dnsbl[hooks=0xffffffff,flags=0x0000] for query
>> 668445e8da5533e5[QUERY_CONNECT=178.21.114.197 <->
>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x9acbf0[datalen=0,eom=(nil),ofile=(nil)]]
>> filter: waiting for running query
>> 668445e8da5533e5[QUERY_CONNECT=178.21.114.197 <->
>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x9acbf0[datalen=0,eom=(nil),ofile=(nil)]]
>> dnsbl[24002]: debug: on_connect: checking 222.168.14.185.psbl.surriel.com.
>> dnsbl[24002]: warn: session 668445e741ecfaa7: event_dispatch: REJECT address
>> ar_gai_errno=-5
>> filter: imsg IMSG_FILTER_RESPONSE from procfilter
>> dnsbl[hooks=0xffffffff,flags=0x0000]
>> filter: filter_drain_query 668445e8da5533e5[QUERY_CONNECT=178.21.114.197 <->
>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x9acbf0[datalen=0,eom=(nil),ofile=(nil)]]
>> filter: filter_end_query 668445e8da5533e5[QUERY_CONNECT=178.21.114.197 <->
>> 185.14.168.222(pro-mail-smtp-001.bol.com),filter_session@0x9acbf0[datalen=0,eom=(nil),ofile=(nil)]]
>> filter: query 668445e8da5533e5 done: status=FILTER_CLOSE code=554
>> response="5.7.1 Address in DNSBL"
>> smtp-in: Failed command on session 668445e741ecfaa7: "" => 554 5.7.1 Address
>> in DNSBL
>> smtp-in: Closing session 668445e741ecfaa7
>> debug: smtp: 0xa70cb0: deleting session: done
>> filter: post-event event=EVENT_DISCONNECT filter=dnsbl
>>
>> I am not sure what 'event_dispatch: REJECT address ar_gai_errno=-5’ means..
>
> So, this is strange, I’m bit confused now :(
> You have only modified Line 45 in dnsbl_event_dispatch(), right?
yes, like you said
> Can you show me your whole modified dnsbl_event_dispatch(), please?
tatic void
dnsbl_event_dispatch(struct asr_result *ar, void *arg)
{
uint64_t *q = arg;
if (ar->ar_addrinfo)
freeaddrinfo(ar->ar_addrinfo);
if (ar->ar_gai_errno != EAI_NODATA) {
log_warnx("warn: session %016"PRIx64": event_dispatch: REJECT
address ar_gai_errno=%d", *q, ar->ar_gai_errno);
filter_api_reject_code(*q, FILTER_CLOSE, 554, "5.7.1 Address in
DNSBL");
} else
filter_api_accept(*q);
free(q);
}
>
> gai_errno=-5 means: EAI_NODATA — because, it is defined in netdb.h:
> #define EAI_NODATA -5 /* no address associated with name */
>
> This is expected and fine because IP is not listed and not found.
>
> BUT, in line 44 in dnsbl_event_dispatch() we have:
>
> if (ar->ar_gai_errno != EAI_NODATA) {
> …
>
> How come that it enters the if statement, when it should NOT?
>
> Can you also please print the value of EAI_NODATA? e.g. can you add the
> following in line 43 right before the if statement:
> log_warnx("warn: DEBUG: ar_gai_errno=%d, EAI_NODATA=%d", ar->ar_gai_errno,
> EAI_NODATA);
>
done.
code looks like:
dnsbl_event_dispatch(struct asr_result *ar, void *arg)
{
uint64_t *q = arg;
if (ar->ar_addrinfo)
freeaddrinfo(ar->ar_addrinfo);
log_warnx("warn: DEBUG: ar_gai_errno=%d, EAI_NODATA=%d",
ar->ar_gai_errno, EAI_NODATA);
if (ar->ar_gai_errno != EAI_NODATA) {
log_warnx("warn: session %016"PRIx64": event_dispatch: REJECT
address ar_gai_errno=%d", *q, ar->ar_gai_errno);
filter_api_reject_code(*q, FILTER_CLOSE, 554, "5.7.1 Address in
DNSBL");
} else
filter_api_accept(*q);
free(q);
}
result:
debug: smtp: new client on listener: 0x1f370f0
smtp-in: New session 2bda822bf9abd4a7 from host pro-mail-smtp-002.bol.com
[185.14.169.222]
filter: post-event event=EVENT_CONNECT filter=dnsbl
filter: new query QUERY_CONNECT
filter: filter_drain_query 2bda822cbded033e[QUERY_CONNECT=178.21.114.197 <->
185.14.169.222(pro-mail-smtp-002.bol.com),filter_session@0x1f2fbf0[datalen=0,eom=(nil),ofile=(nil)]]
filter: running filter filter:dnsbl[hooks=0xffffffff,flags=0x0000] for query
2bda822cbded033e[QUERY_CONNECT=178.21.114.197 <->
185.14.169.222(pro-mail-smtp-002.bol.com),filter_session@0x1f2fbf0[datalen=0,eom=(nil),ofile=(nil)]]
filter: waiting for running query 2bda822cbded033e[QUERY_CONNECT=178.21.114.197
<->
185.14.169.222(pro-mail-smtp-002.bol.com),filter_session@0x1f2fbf0[datalen=0,eom=(nil),ofile=(nil)]]
dnsbl[25105]: debug: on_connect: checking 222.169.14.185.psbl.surriel.com.
dnsbl[25105]: warn: DEBUG: ar_gai_errno=-5, EAI_NODATA=-2
dnsbl[25105]: warn: session 2bda822bf9abd4a7: event_dispatch: REJECT address
ar_gai_errno=-5
filter: imsg IMSG_FILTER_RESPONSE from procfilter
dnsbl[hooks=0xffffffff,flags=0x0000]
filter: filter_drain_query 2bda822cbded033e[QUERY_CONNECT=178.21.114.197 <->
185.14.169.222(pro-mail-smtp-002.bol.com),filter_session@0x1f2fbf0[datalen=0,eom=(nil),ofile=(nil)]]
filter: filter_end_query 2bda822cbded033e[QUERY_CONNECT=178.21.114.197 <->
185.14.169.222(pro-mail-smtp-002.bol.com),filter_session@0x1f2fbf0[datalen=0,eom=(nil),ofile=(nil)]]
filter: query 2bda822cbded033e done: status=FILTER_CLOSE code=554
response="5.7.1 Address in DNSBL"
smtp-in: Failed command on session 2bda822bf9abd4a7: "" => 554 5.7.1 Address in
DNSBL
smtp-in: Closing session 2bda822bf9abd4a7
debug: smtp: 0x1ff3cb0: deleting session: done
filter: post-event event=EVENT_DISCONNECT filter=dnsbl
>
--
You received this mail because you are subscribed to misc@opensmtpd.org
To unsubscribe, send a mail to: misc+unsubscr...@opensmtpd.org
