[RPZ] assertion failures

Wed Jun 29 15:05:36 UTC 2011

My RPZ test server works as expected for awhile and then bind stops
with assertion failure in log. My guess is that others are not seeing
this problem because most don't compile with the --enable-rpz-nsip and
--enable-rpz-nsdname as I did, and they may not be using RPZ rules
that exercise those features.

Believing this is a bind issue, I went to ask about it or report it to
the bind list and searched / read archives first. I will need a stack
trace they say or the report won't be helpful. I searched for how to
get a stack trace and find no info. I went to the #bind channel on
freenode and asked but did not receive an answer.

I think some of the early adopters of RPZ domain rules also had
assertion failures and may be able to tell me the path to take to get
the stack trace to send to the bind bugs address. The OS of this test
server is Ubuntu natty. My *bsd oriented friends think it will be hard
to get a stack trace on linux.

At this point I am stuck unless I bother people I know in ISC. I would
hope or assume there is some other more appropriate path to the right
person to help me that I haven't discovered yet.

I believe anyone could recreate the symptoms by compiling with the
nsip and nsdname options and running a list of miscreant domains
against a server with an RPZ list of malicious ns ips.

Compiled with these options:
./configure --prefix=/opt/bind9 --with-openssl=yes
--sysconfdir=/etc/bind --with-randomdev=/dev/urandom --enable-rpz-nsip
--enable-rpz-nsdname

Examples of how the failures happen:

29-Jun-2011 02:52:29.733 client MY.HOME.IP#64760: response policy NSIP
rewrite 0DAY-EXCHANGE.COM via 0DAY-EXCHANGE.COM NS db_find() failed:
failure
29-Jun-2011 02:52:32.380 client MY.HOME.IP#65516: response policy NSIP
rewrite 0EC.RU via 0EC.RU NS db_find() failed: failure
29-Jun-2011 02:52:35.530 client MY.HOME.IP#63528: response policy NSIP
rewrite 07TQQWEM.RU via 07TQQWEM.RU NS db_find() failed: timed out
29-Jun-2011 02:52:36.807 name.c:2112: REQUIRE(suffixlabels <
name->labels) failed, back trace
29-Jun-2011 02:52:36.807 #0 0x412ff6 in assertion_failed()+0x46
29-Jun-2011 02:52:36.807 #1 0x56969a in isc_assertion_failed()+0xa
29-Jun-2011 02:52:36.807 #2 0x494119 in dns_name_split()+0x199
29-Jun-2011 02:52:36.807 #3 0x416c8a in rpz_rewrite_name()+0xea
29-Jun-2011 02:52:36.807 #4 0x41f0cb in query_find()+0x329b
29-Jun-2011 02:52:36.807 #5 0x42282f in query_resume()+0x21f
29-Jun-2011 02:52:36.807 #6 0x584cf5 in isc__taskmgr_dispatch()+0x175
29-Jun-2011 02:52:36.807 #7 0x58741f in evloop()+0x9f
29-Jun-2011 02:52:36.807 #8 0x587677 in isc__app_ctxrun()+0x87
29-Jun-2011 02:52:36.807 #9 0x414184 in main()+0xbf4
29-Jun-2011 02:52:36.807 #10 0x7f76e89d6eff in _fini()+0x7f76e84401a7
29-Jun-2011 02:52:36.807 #11 0x404f49 in _start()+0x29
29-Jun-2011 02:52:36.807 exiting (due to assertion failure)

(I restarted bind and after properly handling some queries... )

29-Jun-2011 13:14:03.430 client MY.HOME.IP#60741: response policy NSIP
rewrite 2FVWP6VLTT4VSJ3.INFO via 2FVWP6VLTT4VSJ3.INFO NS db_find()
failed: timed out
29-Jun-2011 13:14:34.922 client MY.HOME.IP#60859: response policy NSIP
rewrite 2GOPLAY.COM via 2GOPLAY.COM NS db_find() failed: timed out
29-Jun-2011 13:14:37.366 DNS format error from 74.54.83.109#53
resolving ns2.supernetdeal.com.directideleteddomain.info/AAAA: invalid
response
29-Jun-2011 13:14:37.369 DNS format error from 74.54.83.109#53
resolving ns1.supernetdeal.com.directideleteddomain.info/AAAA: invalid
response
29-Jun-2011 13:14:37.404 DNS format error from 74.54.82.109#53
resolving ns2.supernetdeal.com.directideleteddomain.info/AAAA: invalid
response
29-Jun-2011 13:14:37.405 DNS format error from 74.54.82.109#53
resolving ns1.supernetdeal.com.directideleteddomain.info/AAAA: invalid
response
29-Jun-2011 13:14:49.931 client MY.HOME.IP#54007: response policy NSIP
rewrite 2H8FWYIVDSGRSDD.INFO via 2H8FWYIVDSGRSDD.INFO NS db_find()
failed: timed out
29-Jun-2011 13:15:07.246 client MY.HOME.IP#52729: response policy NSIP
rewrite 2HFNWZ9NKWF2DNJ.INFO via 2HFNWZ9NKWF2DNJ.INFO NS db_find()
failed: timed out
29-Jun-2011 13:15:08.444 rdataset.c:245: REQUIRE(rdataset->methods !=
((void *)0)) failed, back trace
29-Jun-2011 13:15:08.444 #0 0x412ff6 in assertion_failed()+0x46
29-Jun-2011 13:15:08.444 #1 0x56969a in isc_assertion_failed()+0xa
29-Jun-2011 13:15:08.444 #2 0x4ee3a0 in dns_rdataset_next()+0x0
29-Jun-2011 13:15:08.444 #3 0x4ef26d in dns_rdataset_additionaldata()+0x6d
29-Jun-2011 13:15:08.444 #4 0x41619c in query_addrdataset()+0x8c
29-Jun-2011 13:15:08.444 #5 0x419d03 in query_addrrset()+0x143
29-Jun-2011 13:15:08.444 #6 0x41e1fe in query_find()+0x23ce
29-Jun-2011 13:15:08.444 #7 0x42282f in query_resume()+0x21f
29-Jun-2011 13:15:08.444 #8 0x584cf5 in isc__taskmgr_dispatch()+0x175
29-Jun-2011 13:15:08.444 #9 0x58741f in evloop()+0x9f
29-Jun-2011 13:15:08.444 #10 0x587677 in isc__app_ctxrun()+0x87
29-Jun-2011 13:15:08.444 #11 0x414184 in main()+0xbf4
29-Jun-2011 13:15:08.444 #12 0x7f0328b2deff in _fini()+0x7f03285971a7
29-Jun-2011 13:15:08.444 #13 0x404f49 in _start()+0x29
29-Jun-2011 13:15:08.444 exiting (due to assertion failure)

(I restarted bind and after properly handling some queries...)

29-Jun-2011 13:42:04.510 client MY.HOME.IP#39962: response policy NSIP
rewrite jouwstrandreis.com via jouwstrandreis.com NS db_find() faile
d: failure
29-Jun-2011 13:42:04.516 client MY.HOME.IP#39962: response policy NSIP
rewrite helevakantiegratis.com via helevakantiegratis.com NS db_find
() failed: failure
29-Jun-2011 13:42:04.539 client MY.HOME.IP#39962: response policy NSIP
rewrite nikefreesko.org via nikefreesko.org NS db_find() failed: fai
lure
29-Jun-2011 13:42:04.540 client MY.HOME.IP#39962: response policy NSIP
rewrite topreisgratis.com via topreisgratis.com NS db_find() failed:
 failure
29-Jun-2011 13:42:04.576 DNS format error from 112.90.143.29#53
resolving szxintian.com/A for client MY.HOME.IP#39962: reply has no
answer
29-Jun-2011 13:42:04.585 DNS format error from 112.90.143.29#53
resolving 231423423.com/A for client MY.HOME.IP#39962: reply has no
answer
29-Jun-2011 13:42:04.597 DNS format error from 125.39.58.12#53
resolving anlucn.com/A for client MY.HOME.IP#39962: reply has no
answer
29-Jun-2011 13:42:04.724 DNS format error from 183.60.52.217#53
resolving 231423423.com/NS for client MY.HOME.IP#39962: reply has no
answer
29-Jun-2011 13:42:04.825 DNS format error from 183.60.52.217#53
resolving 231423423.com/A for client MY.HOME.IP#39962: reply has no
answer
29-Jun-2011 13:42:04.836 DNS format error from 122.225.217.191#53
resolving szxintian.com/NS for client MY.HOME.IP#39962: reply has no
answ
er
29-Jun-2011 13:42:04.875 client MY.HOME.IP#39962: response policy NSIP
rewrite best--buy.com via best--buy.com NS db_find() failed: failure
29-Jun-2011 13:42:04.891 DNS format error from 112.90.143.29#53
resolving anlucn.com/A for client MY.HOME.IP#39962: reply has no
answer29-Jun-2011 13:42:04.910 success resolving '163ebhk.com/NS' (in
'163ebhk.COM'?) after reducing the advertised EDNS UDP packet size to
512 octet
s
29-Jun-2011 13:42:04.956 success resolving 'vscos.com/A' (in
'vscos.COM'?) after reducing the advertised EDNS UDP packet size to
512 octets
29-Jun-2011 13:42:05.018 DNS format error from 112.90.143.29#53
resolving 231423423.com/NS for client MY.HOME.IP#39962: reply has no
answer29-Jun-2011 13:42:05.087 DNS format error from
122.225.217.191#53 resolving 231423423.com/A for client
MY.HOME.IP#39962: reply has no answe
r
29-Jun-2011 13:42:05.130 DNS format error from 112.90.143.29#53
resolving szxintian.com/NS for client MY.HOME.IP#39962: reply has no
answer29-Jun-2011 13:42:05.148 db.c:569: REQUIRE((((db) != ((void
*)0)) && (((const isc__magic_t *)(db))->magic == ((('D') << 24 | ('N')
<< 16 | ('S'
) << 8 | ('D')))))) failed, back trace
29-Jun-2011 13:42:05.148 #0 0x412ff6 in assertion_failed()+0x46
29-Jun-2011 13:42:05.148 #1 0x56969a in isc_assertion_failed()+0xa
29-Jun-2011 13:42:05.148 #2 0x466d61 in dns_db_detachnode()+0x41
29-Jun-2011 13:42:05.148 #3 0x41c569 in query_find()+0x739
29-Jun-2011 13:42:05.148 #4 0x42282f in query_resume()+0x21f
29-Jun-2011 13:42:05.148 #5 0x584cf5 in isc__taskmgr_dispatch()+0x175
29-Jun-2011 13:42:05.148 #6 0x58741f in evloop()+0x9f
29-Jun-2011 13:42:05.148 #7 0x587677 in isc__app_ctxrun()+0x87
29-Jun-2011 13:42:05.148 #8 0x414184 in main()+0xbf4
29-Jun-2011 13:42:05.148 #9 0x7f3ddf9d2eff in _fini()+0x7f3ddf43c1a7
29-Jun-2011 13:42:05.148 #10 0x404f49 in _start()+0x29
29-Jun-2011 13:42:05.148 exiting (due to assertion failure)