Zonemgr not reacting to notifies

Spain, Dr. Jeffry A. spainj at countryday.net
Tue Jun 5 14:09:37 UTC 2012


I have a bind10-devel-20120517 system set up as a slave server that uses a bind 9.9.1-P1 server as a master. The latter does DNSSEC inline signing. The bind10 slave appears not to be reacting to notify messages received -- it is not transferring the updated zone from the master. It does finally transfer the zone three hours later, presumably as a result of the SOA refresh timer (86400) expiring. I have included excerpts from the bind10 system's log (set to DEBUG level) and excerpts from the configuration. I would like to have your opinion as to whether the incoming notify process is malfunctioning or if I have made a configuration error. Thanks. Jeff.

Following is what I see in the logs on the bind10 system. It received two notify messages associated with two successive zone updates for jaspain.net with SOA serial numbers 2012060302 and 2012060304. The existing serial number had been from May 20.

2012-06-04 21:17:37.417 DEBUG [b10-zonemgr.zonemgr] ZONEMGR_RECEIVE_NOTIFY received NOTIFY command for zone jaspain.net. (class IN)
2012-06-04 21:17:41.940 DEBUG [b10-zonemgr.zonemgr] ZONEMGR_RECEIVE_NOTIFY received NOTIFY command for zone jaspain.net. (class IN)
2012-06-04 21:18:39.123 DEBUG [b10-auth.datasrc] DATASRC_QUERY_PROCESS processing query 'jaspain.net./SOA' in the 'IN' class
2012-06-04 21:18:49.298 DEBUG [b10-auth.datasrc] DATASRC_QUERY_PROCESS processing query 'jaspain.net./SOA' in the 'IN' class

There was no indication of an attempt to transfer the zone based on the notification with an updated serial number. The jaspain.net zone data was updated three hours later, along with the jaspain.us zone. Note the error messages "ZONEMGR_NO_MASTER_ADDRESS internal BIND 10 command did not contain address of master".

2012-06-05 00:39:02.894 DEBUG [b10-zonemgr.zonemgr] ZONEMGR_REFRESH_ZONE refreshing zone jaspain.net. (class IN)
2012-06-05 00:39:02.897 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_NEWCONN SQLite3Database is being initialized
2012-06-05 00:39:02.897 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNOPEN Opening sqlite database file '/var/bind10-devel/zone.sqlite3'
2012-06-05 00:39:02.899 DEBUG [b10-zonemgr.zonemgr] ZONEMGR_REFRESH_ZONE refreshing zone jaspain.us. (class IN)
2012-06-05 00:39:02.901 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_NEWCONN SQLite3Database is being initialized
2012-06-05 00:39:02.901 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNOPEN Opening sqlite database file '/var/bind10-devel/zone.sqlite3'
2012-06-05 00:39:02.904 INFO  [b10-xfrin.xfrin] XFRIN_XFR_TRANSFER_STARTED AXFR transfer of zone jaspain.net/IN started
2012-06-05 00:39:02.905 INFO  [b10-xfrin.xfrin] XFRIN_XFR_TRANSFER_STARTED AXFR transfer of zone jaspain.us/IN started
2012-06-05 00:39:02.945 DEBUG [b10-xfrin.xfrin] XFRIN_GOT_NONINCREMENTAL_RESP got nonincremental response for jaspain.us/IN
2012-06-05 00:39:02.945 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_NEWCONN SQLite3Database is being initialized
2012-06-05 00:39:02.945 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNOPEN Opening sqlite database file '/var/bind10-devel/zone.sqlite3'
2012-06-05 00:39:02.965 DEBUG [b10-xfrin.xfrin] XFRIN_GOT_NONINCREMENTAL_RESP got nonincremental response for jaspain.net/IN
2012-06-05 00:39:02.965 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_NEWCONN SQLite3Database is being initialized
2012-06-05 00:39:02.965 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNOPEN Opening sqlite database file '/var/bind10-devel/zone.sqlite3'
2012-06-05 00:39:02.977 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_DROPCONN SQLite3Database is being deinitialized
2012-06-05 00:39:02.977 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNCLOSE Closing sqlite database
2012-06-05 00:39:02.977 INFO  [b10-xfrin.xfrin] XFRIN_TRANSFER_SUCCESS full AXFR transfer of zone jaspain.us/IN succeeded (messages: 1, records: 32, bytes: 3718, run time: 0.075 seconds, 49832 bytes/second)
2012-06-05 00:39:02.978 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_DROPCONN SQLite3Database is being deinitialized
2012-06-05 00:39:02.978 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNCLOSE Closing sqlite database
2012-06-05 00:39:02.978 INFO  [b10-xfrin.xfrin] XFRIN_TRANSFER_SUCCESS full AXFR transfer of zone jaspain.net/IN succeeded (messages: 1, records: 44, bytes: 4910, run time: 0.080 seconds, 61331 bytes/second)
2012-06-05 00:39:06.984 ERROR [b10-zonemgr.zonemgr] ZONEMGR_NO_MASTER_ADDRESS internal BIND 10 command did not contain address of master
2012-06-05 00:39:06.985 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_DROPCONN SQLite3Database is being deinitialized
2012-06-05 00:39:06.985 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNCLOSE Closing sqlite database
2012-06-05 00:39:10.990 ERROR [b10-zonemgr.zonemgr] ZONEMGR_NO_MASTER_ADDRESS internal BIND 10 command did not contain address of master
2012-06-05 00:39:10.991 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_DROPCONN SQLite3Database is being deinitialized
2012-06-05 00:39:10.991 DEBUG [b10-xfrin.datasrc] DATASRC_SQLITE_CONNCLOSE Closing sqlite database

I'm not sure whether or not the error message is related to the problem. The bind10 slave is configured as shown in the excerpt below, which includes a master address:

Zonemgr/secondary_zones[2]/class        "IN"    string
Zonemgr/secondary_zones[2]/name "jaspain.net"   string

Xfrin/zones[2]/name     "jaspain.net"   string
Xfrin/zones[2]/class    "IN"    string  (default)
Xfrin/zones[2]/master_addr      "<IPv6 address of master>"        string
Xfrin/zones[2]/master_port      53      integer (default)
Xfrin/zones[2]/tsig_key "nsb0s-nsb1:<Base-64 Key>:hmac-sha256"   string
Xfrin/zones[2]/use_ixfr false   boolean (default)

Jeffry A. Spain
Network Administrator
Cincinnati Country Day School


More information about the bind10-users mailing list