[bind10-dev] b10-auth behaviour and builtin records and hot cache ...

Tue Jun 21 21:46:28 UTC 2011

See this b10-auth output.... only one query which is:
version.bind.                  CH      TXT

The output follows.... see my 19 points at the end of this email.

2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_CREATE, creating the hotspot cache
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_CREATE, creating the static datasource
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_ADD, adding a data source into meta data source
2011-06-21 16:54:22.q INFO  [b10-auth.datasrc] DATASRC_CACHE_ENABLE, enabling the cache
[b10-auth] Server created.
[b10-auth] DNSServices created.
[b10-auth] Configuration session channel created.
Setting listen addresses:
 10.53.0.1:53210
Initialize TCP server at 10.53.0.1:53210
Initialize UDP server at 10.53.0.1:53210
[b10-auth] Set statistics timer to 1 seconds
[b10-auth] Data source database file: /usr/home/jreed/builder/work/BIND10-cppcheck/20110621143000-FreeBSD8-amd64-GCC/build/tests/system/bindctl/nsx1/zone.sqlite3
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_CREATE, SQLite data source created
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_OPEN, opening SQLite database '/usr/home/jreed/builder/work/BIND10-cppcheck/20110621143000-FreeBSD8-amd64-GCC/build/tests/system/bindctl/nsx1/zone.sqlite3'
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_ADD, adding a data source into meta data source
[b10-auth] Configuration channel established.
[b10-auth] Xfrin session channel created.
[b10-auth] Xfrin session channel established.
[b10-auth] Statistics session channel created.
[b10-auth] Statistics session channel established.
Setting listen addresses:
 10.53.0.1:53210
Initialize TCP server at 10.53.0.1:53210
Initialize UDP server at 10.53.0.1:53210
[b10-auth] Set statistics timer to 1 seconds
[b10-auth] Data source database file: /usr/home/jreed/builder/work/BIND10-cppcheck/20110621143000-FreeBSD8-amd64-GCC/build/tests/system/bindctl/nsx1/zone.sqlite3
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_CREATE, SQLite data source created
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_OPEN, opening SQLite database '/usr/home/jreed/builder/work/BIND10-cppcheck/20110621143000-FreeBSD8-amd64-GCC/build/tests/system/bindctl/nsx1/zone.sqlite3'
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_ADD, adding a data source into meta data source
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_REMOVE, removing data source from meta data source
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_DESTROY, SQLite data source destroyed
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_CLOSE, closing SQLite database
[b10-auth] Loading TSIG keys
[b10-auth] Configuration channel started.
[b10-auth] Server started.
[b10-auth] received a message:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 14175
;; flags: rd; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;version.bind. CH TXT

2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_PROCESS, processing query 'version.bind./CH' in the '%3' class
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_DELEGATION, looking for delegation on the path to 'version.bind.'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_ENCLOSURE, looking for zone containing 'version.bind.'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_DO_QUERY, handling query for 'version.bind./TXT'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_CHECK_CACHE, checking cache for 'version.bind./TXT'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_IS_AUTH, auth query (version.bind./TXT)
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./TXT'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'negative entry for version.bind. CH CNAME
' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'version.bind.' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_ADD_RRSET, adding RRset 'version.bind./TXT' to message
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_DO_QUERY, handling query for 'version.bind./TYPE255'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_CHECK_CACHE, checking cache for 'version.bind./TYPE255'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_IS_REF, query for referral (version.bind./TYPE255)
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./NS'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./DS'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./DNAME'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'version.bind.' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'negative entry for version.bind. CH DS
' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'negative entry for version.bind. CH DNAME
' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_COPY_AUTH, copying authoritative section into message
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_ADD_RRSET, adding RRset 'version.bind./NS' to message
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_GET_NS_ADDITIONAL, addition of A/AAAA for 'version.bind.' requested by NS 'version.bind.'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_DO_QUERY, handling query for 'version.bind./TYPE255'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_ENCLOSURE, looking for zone containing 'version.bind.'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_CHECK_CACHE, checking cache for 'version.bind./TYPE255'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_IS_GLUE, glue query (version.bind./TYPE255)
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./A'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_STATIC_FIND, looking for 'version.bind./AAAA'
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'negative entry for version.bind. CH A
' into the cache
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, inserting item 'negative entry for version.bind. CH AAAA
' into the cache
[b10-auth] sending a response (78 bytes):
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 14175
;; flags: qr aa rd; QUERY: 1, ANSWER: 1, AUTHORITY: 1, ADDITIONAL: 0

;; QUESTION SECTION:
;version.bind. CH TXT

;; ANSWER SECTION:
version.bind. 0 CH TXT "bind10-devel 20110519"

;; AUTHORITY SECTION:
version.bind. 0 CH NS version.bind.

-=-=-=-=-

1) notice some output is not using the new logging routines.

2) "DATASRC_META_ADD, adding a data source into meta data source"

This is generic, so I don't know why is repeated. Be more specific?

3) "[b10-auth] Xfrin session channel established."

I never started any b10-xfrin. Why or how established?

4) "[b10-auth] Statistics session channel established."

I never started any b10-stats. Why or how established?

5) Some repeats:

Setting listen addresses:
 10.53.0.1:53210
Initialize TCP server at 10.53.0.1:53210
Initialize UDP server at 10.53.0.1:53210

Why repeated?

6) [b10-auth] Set statistics timer to 1 seconds

Why repeated?

7)

2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_CREATE, 
SQLite data source created
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_OPEN, 
opening SQLite database 
'/usr/home/jreed/builder/work/BIND10-cppcheck/20110621143000-FreeBSD8-amd64-GCC/build/tests/system/bindctl/nsx1/zone.sqlite3'
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_ADD, adding 
a data source into meta data source

Why repeated?

8) 

2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_META_REMOVE, 
removing data source from meta data source
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_DESTROY, 
SQLite data source destroyed
2011-06-21 16:54:22.q DEBUG [b10-auth.datasrc] DATASRC_SQLITE_CLOSE, 
closing SQLite database

Why removed, destroyed, and closed?

9) "[b10-auth] Loading TSIG keys"

What TSIG keys loaded?

I never configured any.

10)

2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_QUERY_DELEGATION, 
looking for delegation on the path to 'version.bind.'

Should it look at outside datasources before builtin?  Did we make this 
decision? Where documented?

11) 

2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, 
the item 'version.bind.' was not found
2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_NOT_FOUND, 
the item 'version.bind.' was not found

Why repeated?

12)

2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_CACHE_INSERT, 
inserting item 'negative entry for version.bind. CH CNAME
' into the cache

Why insert a negative entry into hot cache for something that is built 
in to the binary?

13) And why insert a CNAME?

14) Ignore the formatting issue ... that is ticket #571.

15) Also ignore the ".q" time stamp. That is ticket #1033.

16) 

2011-06-21 16:54:27.q DEBUG [b10-auth.datasrc] DATASRC_DO_QUERY, 
handling query for 'version.bind./TYPE255'

Why look for "ANY"?  My question was specific for TXT.

17) And then it looks for referral for that (NS and DS and DNAME) and 
then puts negative entries for the DS and DNAME in hot cache.  Why?

18) Then does glue queries and puts A and AAAA negative entries (for NS) 
into hot cache. Why?