misc@,
I dig into issue when callback which is scheduled via res_query_async never
fired inside opensmtpd filter which uses libopensmtpd.
I've tried both res_query_async and getrrsetbyname_async without any
differences on OpenBSD 7.5
The code looks like:
if ((query =
getrrsetbyname_async(domain, C_IN, T_TXT, 0, NULL)) ==
NULL)
osmtpd_err(1, "res_query_async");
if ((sig->query = event_asr_run(query, ar_rr_resolve, sig)) == NULL)
osmtpd_err(1, "event_asr_run");
where ar_rr_resolve is callback which need to be fired, the whole code:
https://github.com/catap/opensmtpd-filter-auth/blob/master/main.c#L863-L881
For one event loop it may setup a few quereis and some domain migth similar.
After spending a lot of time with debug I narrow down to the issue in
event_asr_dispatch which re-schedule event_add, and it never had happened.
Nor timeout, nor inout, nothing. Not always. Sometimes.
Thus, I've rebuild libc with enabled debug to use ASR_DEBUG and here an
output which proves that behaviour.
Anyway, I'm puzzling that to do next.
tcpdump:
14:09:36.760807 127.0.0.1.44226 > 127.0.0.1.53: [bad udp cksum 50fe! -> de34]
64311+ TXT? 20240125rsa._domainkey.mx.catap.net.(53) (ttl 64, id 35656, len 81,
bad ip cksum 0! -> f151)
14:09:36.785096 127.0.0.1.53 > 127.0.0.1.44226: 64311$ q: TXT?
20240125rsa._domainkey.mx.catap.net. 2/0/0 20240125rsa._domainkey.mx.catap.net.
CNAME[|domain] (ttl 64, id 25945, len 533, bad ip cksum 0! -> 157d)
14:09:36.785283 127.0.0.1.15520 > 127.0.0.1.53: [bad udp cksum 4cfe! -> 6b81]
2100+ TXT? 20240125rsa.domainkey.catap.net.(49) (ttl 64, id 27815, len 77, bad
ip cksum 0! -> ff7)
14:09:36.785305 127.0.0.1.53 > 127.0.0.1.15520: 2100$ q: TXT?
20240125rsa.domainkey.catap.net. 1/0/0 20240125rsa.domainkey.catap.net.
TXT[|domain] (ttl 64, id 15297, len 493, bad ip cksum 0! -> 3f3d)
14:09:36.863795 127.0.0.1.18298 > 127.0.0.1.53: [bad udp cksum 50fe! -> 4fc4]
53518+ TXT? 20240125rsa._domainkey.mx.catap.net.(53) (ttl 64, id 23044, len 81,
bad ip cksum 0! -> 2296)
14:09:36.863838 127.0.0.1.53 > 127.0.0.1.18298: 53518$ q: TXT?
20240125rsa._domainkey.mx.catap.net. 2/0/0 20240125rsa._domainkey.mx.catap.net.
CNAME[|domain] (ttl 64, id 51168, len 533, bad ip cksum 0! -> b2f5)
14:09:36.863990 127.0.0.1.36692 > 127.0.0.1.53: [bad udp cksum 4dfe! -> 41fd]
14366+ TXT? 20240125rsa._domainkey.korins.ky.(50) (ttl 64, id 61731, len 78,
bad ip cksum 0! -> 8b79)
14:09:36.865962 127.0.0.1.2727 > 127.0.0.1.53: [bad udp cksum 4cfe! -> 94e4]
55043+ TXT? 20240125rsa.domainkey.catap.net.(49) (ttl 64, id 32069, len 77, bad
ip cksum 0! -> ff58)
14:09:36.865977 127.0.0.1.53 > 127.0.0.1.2727: 55043$ q: TXT?
20240125rsa.domainkey.catap.net. 1/0/0 20240125rsa.domainkey.catap.net.
TXT[|domain] (ttl 64, id 57083, len 493, bad ip cksum 0! -> 9c02)
14:09:36.866528 127.0.0.1.45954 > 127.0.0.1.53: [bad udp cksum 51fe! -> 8452]
25459+ TXT? 20240125ed25519._domainkey.korins.ky.(54) (ttl 64, id 15424, len
82, bad ip cksum 0! -> 4059)
14:09:36.896741 127.0.0.1.53 > 127.0.0.1.36692: 14366$ q: TXT?
20240125rsa._domainkey.korins.ky. 2/0/0 20240125rsa._domainkey.korins.ky.
CNAME[|domain] (ttl 64, id 1532, len 539, bad ip cksum 0! -> 74d4)
14:09:36.997396 127.0.0.1.53 > 127.0.0.1.45954: 25459$ q: TXT?
20240125ed25519._domainkey.korins.ky. 2/0/0
20240125ed25519._domainkey.korins.ky. CNAME[|domain] (ttl 64, id 37600, len
208, bad ip cksum 0! -> e93a)
asr log:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: checking for update of
"/etc/resolv.conf"
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=1
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672e1460,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125rsa._domainkey.mx.catap.net.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x37fb op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672e1460]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310620,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310620]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310620]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f67310620] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310620]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310620,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672e1460,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672e1460,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310620,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_udp_recv() -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x37fb QR op:0 RD RA
z:0 AD r:NOERROR qd:1 an:2 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; ANSWER SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net. 60
IN CNAME 20240125rsa.domainkey.catap.net.
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net. 60 IN
TXT (rdlen=404)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310620]
ASR_STATE_UDP_RECV -> ASR_STATE_PACKET
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310620]
ASR_STATE_PACKET -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310620,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f67310620)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672e1460]
ASR_STATE_SUBQUERY -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672e1460,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f672e1460)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=1
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd620,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125rsa.domainkey.catap.net.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x3408 op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672fd620]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd1c0,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672fd1c0]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672fd1c0]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f672fd1c0] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672fd1c0]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd1c0,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd620,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd620,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd1c0,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_udp_recv() -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x3408 QR op:0 RD RA
z:0 AD r:NOERROR qd:1 an:1 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; ANSWER SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net. 60 IN
TXT (rdlen=404)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672fd1c0]
ASR_STATE_UDP_RECV -> ASR_STATE_PACKET
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672fd1c0]
ASR_STATE_PACKET -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd1c0,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f672fd1c0)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672fd620]
ASR_STATE_SUBQUERY -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672fd620,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f672fd620)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=1
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=2
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a2a0,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125rsa._domainkey.mx.catap.net.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x0ed1 op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f6730a2a0]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ae00,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f6730ae00]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f6730ae00]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f6730ae00] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f6730ae00]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ae00,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a2a0,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a0e0,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125rsa._domainkey.korins.ky.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x1e38 op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.korins.ky.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f6730a0e0]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310700,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310700]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310700]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f67310700] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310700]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310700,
0x72f8081d0ea8) -> ASYNC_COND fd=6 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a0e0,
0x72f8081d0ea8) -> ASYNC_COND fd=6 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a2a0,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ae00,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_udp_recv() -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x0ed1 QR op:0 RD RA
z:0 AD r:NOERROR qd:1 an:2 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; ANSWER SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa._domainkey.mx.catap.net. 60
IN CNAME 20240125rsa.domainkey.catap.net.
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net. 60 IN
TXT (rdlen=404)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f6730ae00]
ASR_STATE_UDP_RECV -> ASR_STATE_PACKET
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f6730ae00]
ASR_STATE_PACKET -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ae00,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f6730ae00)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=5
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f6730a2a0]
ASR_STATE_SUBQUERY -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730a2a0,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f6730a2a0)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=5
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9700,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125rsa.domainkey.catap.net.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x03d7 op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672d9700]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310e00,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310e00]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310e00]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f67310e00] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310e00]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310e00,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9700,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9700,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310e00,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_udp_recv() -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x03d7 QR op:0 RD RA
z:0 AD r:NOERROR qd:1 an:1 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; ANSWER SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125rsa.domainkey.catap.net. 60 IN
TXT (rdlen=404)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310e00]
ASR_STATE_UDP_RECV -> ASR_STATE_PACKET
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f67310e00]
ASR_STATE_PACKET -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f67310e00,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f67310e00)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=5
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f672d9700]
ASR_STATE_SUBQUERY -> ASR_STATE_HALT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9700,
0x72f8081d0ea8) -> ASYNC_DONE
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f672d9700)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: using thread-local resolver
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_ref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=2 refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=5
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ac40,
0x72f8081d0ea8) ASR_GETRRSETBYNAME ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr:
res_query_async_ctx("20240125ed25519._domainkey.korins.ky.", 1, 16)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_new(ctx=0x22f67302840)
type=0 refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ----- asr_setup_query -----
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; HEADER id:0x7363 op:0 RD
z:0 AD r:NOERROR qd:1 an:0 ns:0 ar:0
Jun 14 14:09:36 mx0 smtpd[37708]: auth: ;; QUERY SECTION:
Jun 14 14:09:36 mx0 smtpd[37708]: auth: 20240125ed25519._domainkey.korins.ky.
IN TXT
Jun 14 14:09:36 mx0 smtpd[37708]: auth: --------------
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_GETRRSETBYNAME@0x22f6730ac40]
ASR_STATE_INIT -> ASR_STATE_SUBQUERY
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9a80,
0x72f8081d0ea8) ASR_SEND ctx=[0x22f67302840]
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672d9a80]
ASR_STATE_INIT -> ASR_STATE_NEXT_NS
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672d9a80]
ASR_STATE_NEXT_NS -> ASR_STATE_UDP_SEND
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [0x22f672d9a80] connecting to
127.0.0.1:53 UDP
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: [ASR_SEND@0x22f672d9a80]
ASR_STATE_UDP_SEND -> ASR_STATE_UDP_RECV
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f672d9a80,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_run(0x22f6730ac40,
0x72f8081d0ea8) -> ASYNC_COND fd=5 timeout=5000
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f6730a0e0)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f67310700)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=5
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=4
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f6730ac40)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_async_free(0x22f672d9a80)
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=3
Jun 14 14:09:36 mx0 smtpd[37708]: auth: asr: asr_ctx_unref(ctx=0x22f67302840)
refcount=2
--
wbr, Kirill
