> Am 07.04.2016 um 11:51 schrieb Michiel van Es <[email protected]>: > > oops, forgot to reply-all (and miss [email protected]), send again -> > >> On 07 Apr 2016, at 11:30, Joerg Jung <[email protected]> wrote: >> >> >>>> On 07 Apr 2016, at 10:17, Michiel van Es <[email protected]> wrote: >>>> >>>> >>>> On 07 Apr 2016, at 10:02, Joerg Jung <[email protected]> wrote: >>>> >>>> >>>>>> On 07 Apr 2016, at 08:47, Michiel van Es <[email protected]> wrote: >>>>>> On 07 Apr 2016, at 08:41, Joerg Jung <[email protected]> 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
Ok... that makes sense now. -2 seems to be EAI_NONAME which seems to be the error code specific on Ubuntu libc for NXDOMAIN replies, instead of EAI_NODATA. These error codes and related RFCs are subject to a lot of discussions. See here to get an idea: https://sourceware.org/bugzilla/show_bug.cgi?id=15726 Especially, note the cross references to Ubuntu bugs ... Instead of trying to fit all distribution specific changes, the easiest might be to change the logic here and check for the returned address not being empty -- instead of errno. I'll try to come up with a proper diff to fix this, but give me some time as I'm very busy currently. As quick fix: you can just change the if statement to: if (ar->ar_gai_errno != EAI_NODATA && ar->ar_gai_errno != EAI_NONAME) { ... and it should start working as expected. Can you confirm that, please? Thanks, Regards, Jörg -- You received this mail because you are subscribed to [email protected] To unsubscribe, send a mail to: [email protected]
