SA Bugzilla – Bug 6711
DnsResolver: "dns: no callback for id", DNS answer packets ignored as unsolicited
Last modified: 2013-01-17 00:34:16 UTC
A few times per day I see in the logs an info message from SpamAssassin: SA info: dns: no callback for id: 8235/avivabiology.com/NS/IN, ignored; packet: ;; Answer received from ... (86 bytes) followed by a dump of a captured normal DNS answer packet. Adding some debug logging, so far I can recognize two distinct cases of how this happens: case#1: SA dbg: dns: providing a callback for id: 8235/avivabiology.com/NS/IN SA dbg: dns: providing a callback for id: 8235/avivabiology.com/NS/IN SA info: dns: no callback for id: 8235/avivabiology.com/NS/IN, ignored; packet: ;; Answer received from ::1 (86 bytes) case#2: SA dbg: dns: providing a callback for id: 23893/news.dormeo..si/ANY/IN SA info: dns: no callback for id: 23893/news.dormeo.si/ANY/IN, ignored; packet: ;; Answer received from ::1 (256 bytes) SA info: dns: [...] ;; HEADER SECTION SA info: dns: [...] ;; id = 23893 SA info: dns: [...] ;; qr = 1 opcode = QUERY aa = 0 tc = 0 rd = 1 SA info: dns: [...] ;; ra = 1 ad = 0 cd = 0 rcode = NOERROR SA info: dns: [...] ;; qdcount = 1 ancount = 4 nscount = 0 arcount = 0 SA info: dns: [...] SA info: dns: [...] ;; QUESTION SECTION (1 record) SA info: dns: [...] ;; news.dormeo.si. IN ANY SA info: dns: [...] SA info: dns: [...] ;; ANSWER SECTION (4 records) SA info: dns: [...] news.dormeo.si. 1922 IN A 91.198.190.101 SA info: dns: [...] news.dormeo.si. 1922 IN MX 10 mail.avenija.com. SA info: dns: [...] news.dormeo.si. 1922 IN TXT "v=spf1 ip4:91.198.190.1/24 ip4:91.220.213.1/24 include:icpbounce.com -all" SA info: dns: [...] news.dormeo.si. 1922 IN TXT "spf2.0/pra ip4:91.198.190.1/24 ip4:91.220.213.1/24 include:icpbounce.com -all" SA info: dns: [...] SA info: dns: [...] ;; AUTHORITY SECTION (0 records) SA info: dns: [...] SA info: dns: [...] ;; ADDITIONAL SECTION (0 records) SA dbg: dns: bgabort: 23893/news.dormeo..si/ANY/IN In case#1 it seems that two queries for "avivabiology.com/NS" are issued. As the query IDs are stored in %{$self->{id_to_callback}} as hash keys, there is only one copy of the ID kept in evidence, so when the first DNS answer arrives and clears the ID from evidence, the second answer appears unsolicited and is ditched with a warning. In addition, the first of the two callbacks is never called. In case#2 the queried domain contains and empty label field (two consecutive dots). Somewhere this gets sanitized so the DNS query section goes for news.dormeo.si (no double dot), and the answer is in accordance - but this does not match the remembered query ID in %{$self->{id_to_callback}} and it is ditched as unsolicited. At the end the bgabort gives up on waiting for 23893/news.dormeo..si/ANY/IN Probably not new and not a showstopper for 3.4.0, but eventually it should be addressed.
The case #1 is now avoided by a rewrite in Bug 6884, duplicate DNS queries are merged into one query by the new AsyncLoop::bgsend_and_start_lookup(). Case #2 is a duplicate for Bug 6819, now handled more gracefully. Closing. *** This bug has been marked as a duplicate of bug 6819 ***