This time with log file attached Thanks Klaus
Am 23.04.2018 um 14:55 schrieb Klaus Darilion via bind-users: > Hi all! > > Upgrading to Ubuntu 16.04 with Bind 9.10.3 did not solved the problem. > > I enabled debug log (trace 2) and query logging. Unless my monitoring > traffic (~20 Queries every second) the server is idle. > > The server is a xen domU (on a idle hypervisor) with 4 vCPUs and 20G RAM. > > Here the logs from my checker script: > Apr 23 10:35:17 tld-all-tst1 darilion: OK: > Apr 23 10:35:18 tld-all-tst1 darilion: OK: > Apr 23 10:35:24 tld-all-tst1 darilion: FAILED - timeout (3 sec) or > network error querying SOA for hu > Apr 23 10:35:31 tld-all-tst1 darilion: FAILED - timeout (3 sec) or > network error querying SOA for hu > Apr 23 10:35:32 tld-all-tst1 darilion: OK: > Apr 23 10:35:33 tld-all-tst1 darilion: OK: > > Hence, no responses from Bind between 10:35:18 and 10:35:32 > > The debug log during this time is attached. It seems Bind hangs from > 10:35:19.126 to 10:35:30.036, maybe at the end of writing the zone file. > The zone file is around 2.2G. > > The query log also show nothing during this time: > 23-Apr-2018 10:35:18.760 queries: info: client 127.0.0.1#54902 (at): > query: at IN SOA - (83.136.32.84) > 23-Apr-2018 10:35:30.037 queries: info: client 127.0.0.1#53148 (hu): > query: hu IN SOA - (83.136.32.84) > > Continuous Write performance of the disk is ~130MB/s. To me it seems > that Bind is somehow blocked at the end of the zone dump and hence not > answering queries anymore. > > May this be possible? Is somewhere documented how Bind as slave applies > the incoming IXFR to the loaded zone, the journal .... Are there any > locking operations in bind? > > Thanks > Klaus > > > > > > > > Am 15.03.2018 um 14:45 schrieb Klaus Darilion: >> Hi! >> >> I use bind 9.9.5.dfsg-3ubuntu0.17 with around 20 slave zones (from small >> to huge). >> >> I query the SOA of every configured zone once a second to monitor bind. >> >> Once a day my script reports timeouts (3 seconds) querying a SOA. This >> server is a test server, hence it is idle except the monitoring checks. >> >> When inspecting the logs the timeouts are always very close to NOTIFYs >> and zone transfers. Are there any known issues that e.g. bind may >> suspend queries wile applying the zone transfer? Any other ideas what >> could be the reason? >> >> Thanks >> Klaus >> _______________________________________________ >> Please visit https://lists.isc.org/mailman/listinfo/bind-users to >> unsubscribe from this list >> >> bind-users mailing list >> bind-users@lists.isc.org >> https://lists.isc.org/mailman/listinfo/bind-users >> > _______________________________________________ > Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe > from this list > > bind-users mailing list > bind-users@lists.isc.org > https://lists.isc.org/mailman/listinfo/bind-users >
23-Apr-2018 10:34:54.954 general: debug 1: zone_timer: zone si/IN: enter 23-Apr-2018 10:34:54.954 general: debug 1: zone_maintenance: zone si/IN: enter 23-Apr-2018 10:34:54.954 general: debug 1: queue_soa_query: zone si/IN: enter 23-Apr-2018 10:34:54.954 general: debug 1: zone_settimer: zone si/IN: enter 23-Apr-2018 10:34:54.954 general: debug 1: soa_query: zone si/IN: enter 23-Apr-2018 10:34:54.956 general: debug 1: refresh_callback: zone si/IN: enter 23-Apr-2018 10:34:54.956 general: debug 1: refresh_callback: zone si/IN: serial: new 1524474022, old 1524474022 23-Apr-2018 10:34:54.956 general: debug 1: queue_soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.455 general: debug 1: soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.463 general: debug 1: refresh_callback: zone si/IN: enter 23-Apr-2018 10:34:55.463 general: debug 1: refresh_callback: zone si/IN: serial: new 1524474022, old 1524474022 23-Apr-2018 10:34:55.463 general: debug 1: queue_soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.463 general: debug 1: soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.464 general: debug 1: refresh_callback: zone si/IN: enter 23-Apr-2018 10:34:55.465 general: debug 1: refresh_callback: zone si/IN: serial: new 1524474022, old 1524474022 23-Apr-2018 10:34:55.465 general: debug 1: queue_soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.963 general: debug 1: soa_query: zone si/IN: enter 23-Apr-2018 10:34:55.971 general: debug 1: refresh_callback: zone si/IN: enter 23-Apr-2018 10:34:55.971 general: debug 1: refresh_callback: zone si/IN: serial: new 1524474022, old 1524474022 23-Apr-2018 10:34:55.972 general: debug 1: zone_settimer: zone si/IN: enter 23-Apr-2018 10:35:01.608 general: debug 1: zone_timer: zone nl/IN: enter 23-Apr-2018 10:35:01.608 general: debug 1: zone_maintenance: zone nl/IN: enter 23-Apr-2018 10:35:01.609 general: debug 1: zone_dump: zone nl/IN: enter 23-Apr-2018 10:35:01.609 general: debug 1: zone_settimer: zone nl/IN: enter 23-Apr-2018 10:35:01.609 general: debug 1: zone_gotwritehandle: zone nl/IN: enter 23-Apr-2018 10:35:01.609 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 212 23-Apr-2018 10:35:01.610 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 310 23-Apr-2018 10:35:01.611 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 396 23-Apr-2018 10:35:01.612 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 471 ... repeat and repeat .... ... 23-Apr-2018 10:35:19.120 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 993 23-Apr-2018 10:35:19.122 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 993 23-Apr-2018 10:35:19.124 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 993 23-Apr-2018 10:35:19.126 general: debug 1: dumptostreaminc(0x7fe3dc74e010) new nodes -> 993 23-Apr-2018 10:35:30.036 general: debug 1: zone_needdump: zone hamburg/IN: enter 23-Apr-2018 10:35:30.036 general: debug 1: zone_settimer: zone hamburg/IN: enter 23-Apr-2018 10:35:30.037 general: debug 1: zone hamburg/IN: zone transfer finished: success 23-Apr-2018 10:35:30.037 general: info: zone hamburg/IN: transferred serial 1524479704 23-Apr-2018 10:35:30.037 general: debug 1: zone_needdump: zone hamburg/IN: enter 23-Apr-2018 10:35:30.037 general: debug 1: zone_settimer: zone hamburg/IN: enter 23-Apr-2018 10:35:30.037 general: debug 1: zone_settimer: zone hamburg/IN: enter 23-Apr-2018 10:35:30.037 xfer-in: info: transfer of 'hamburg/IN' from 83.136.34.4#53: Transfer status: success 23-Apr-2018 10:35:30.037 xfer-in: info: transfer of 'hamburg/IN' from 83.136.34.4#53: Transfer completed: 1 messages, 186 records, 32819 bytes, 11.576 secs (2835 bytes/sec) 23-Apr-2018 10:35:30.037 notify: info: client 83.136.34.20#7275/key rcode0-distribution: received notify for zone 'at': TSIG 'rcode0-distribution' 23-Apr-2018 10:35:30.038 general: info: zone at/IN: notify from 83.136.34.20#7275: zone is up to date 23-Apr-2018 10:35:30.038 notify: info: client 83.136.34.20#7275/key rcode0-distribution: received notify for zone 'hu': TSIG 'rcode0-distribution' 23-Apr-2018 10:35:30.038 general: info: zone hu/IN: notify from 83.136.34.20#7275: zone is up to date
_______________________________________________ Please visit https://lists.isc.org/mailman/listinfo/bind-users to unsubscribe from this list bind-users mailing list bind-users@lists.isc.org https://lists.isc.org/mailman/listinfo/bind-users
