From owner-freebsd-questions@freebsd.org Thu Aug 17 14:33:22 2017 Return-Path: Delivered-To: freebsd-questions@mailman.ysv.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) by mailman.ysv.freebsd.org (Postfix) with ESMTP id C1928DE4B23 for ; Thu, 17 Aug 2017 14:33:22 +0000 (UTC) (envelope-from byrnejb@harte-lyne.ca) Received: from inet08.hamilton.harte-lyne.ca (inet08.hamilton.harte-lyne.ca [216.185.71.28]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (Client CN "inet08.hamilton.harte-lyne.ca", Issuer "CA_HLL_ISSUER_2016" (not verified)) by mx1.freebsd.org (Postfix) with ESMTPS id 7E9BF745B6 for ; Thu, 17 Aug 2017 14:33:22 +0000 (UTC) (envelope-from byrnejb@harte-lyne.ca) Received: from localhost (localhost [127.0.0.1]) by inet08.hamilton.harte-lyne.ca (Postfix) with ESMTP id 2FBB0622A9 for ; Thu, 17 Aug 2017 10:33:15 -0400 (EDT) X-Virus-Scanned: amavisd-new at harte-lyne.ca Received: from inet08.hamilton.harte-lyne.ca ([127.0.0.1]) by localhost (inet08.hamilton.harte-lyne.ca [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id rujkO_DdXQPc for ; Thu, 17 Aug 2017 10:32:58 -0400 (EDT) Received: from [216.185.71.106] (inet04.hamilton.harte-lyne.ca [216.185.71.24]) (using TLSv1 with cipher ECDHE-RSA-AES256-SHA (256/256 bits)) (Client did not present a certificate) by inet08.hamilton.harte-lyne.ca (Postfix) with ESMTPSA id 54E3A62137 for ; Thu, 17 Aug 2017 10:32:58 -0400 (EDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=harte-lyne.ca; s=dkim_hll; t=1502980378; bh=vpHcZ+YPFPzVF7yfUlx+cEla0m+d3NGA3j4jdyouQkA=; h=In-Reply-To:References:Date:Subject:From:To:Reply-To; b=UOJTn0RxEoS2gGOJ6koAik9i0EDjG/+qxG5oYFScEXSDKAJj1YdqG+RTSqEZOad7k z/7tV+dZqhiim/1PJ1ihxANQclfmyaaoJ0EhRbmomNZNA18J0H/QM/0YbuGw4YhBUK BPl0mJN2L5F9UUpVSOROZNcIGPPmJZ1yuaHR3lUko/p+ukbQnrIkTwey8J+Bp0suJ8 MJ3cl/SvFZRSVRmHzWGPovsb28TSmePH5bdgKfz/RrYplSphFwu0MCLVfQWMcG1rjE gue+aOjRdynVcGAoJ8CA9zbfvxD+qCuYnwDj0DMfmd2f7G4R9NDyPNCeZO6T2GM1r7 hUqgC1EMeDs+w== Received: from 216.185.71.44 (SquirrelMail authenticated user byrnejb_hll) by 216.185.71.106 with HTTP; Thu, 17 Aug 2017 10:32:58 -0400 Message-ID: <7eeceea605f1c7e5d4a786822268e86d.squirrel@216.185.71.106> In-Reply-To: References: Date: Thu, 17 Aug 2017 10:32:58 -0400 Subject: Re: FreeBSD-11 - local_unbound logging From: "James B. Byrne" To: freebsd-questions@freebsd.org Reply-To: byrnejb@harte-lyne.ca User-Agent: SquirrelMail/1.4.22-5.el6 MIME-Version: 1.0 Content-Type: text/plain;charset=iso-8859-1 Content-Transfer-Encoding: 8bit X-Priority: 3 (Normal) Importance: Normal X-BeenThere: freebsd-questions@freebsd.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: User questions List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 17 Aug 2017 14:33:22 -0000 This refers back to an earlier question of mine as to why on one FreeBSD system local_unbound stops resolving. I determined from experimentation that this issue was restricted to our own domain. I therefore setup unbound logging and set the verbosity to 3. This morning I dropped into the office (being on vacation I naturally returned to work. . .) and local_unbound again was not resolving our domain on my workstation but was resolving other domains. Checking the log file during a lookup for one of our internal sites I see this debug trace from unbound: Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: iterator operate: chased to webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: iterator operate: chased to webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: iterator operate: chased to webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: iterator operate: chased to webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sanitize: removing extraneous answer RRset: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was CNAME Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: iterator operate: chased to webfax.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed ANSWER rrset: webfax.harte-lyne.ca. CNAME IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.hamilton.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_state_initial event:module_event_new Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_state_initial event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_wait_module event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.34#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_finished event:module_event_pass Aug 17 10:07:42 unbound[97431:0] info: resolving webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: processQueryTargets: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: sending query: webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: sending to target: <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] debug: iterator[module 1] operate: extstate:module_wait_reply event:module_event_reply Aug 17 10:07:42 unbound[97431:0] info: iterator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: response for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: reply from <.> 216.185.71.33#53 Aug 17 10:07:42 unbound[97431:0] info: query response was NXDOMAIN ANSWER Aug 17 10:07:42 unbound[97431:0] info: finishing processing for webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: validator[module 0] operate: extstate:module_restart_next event:module_event_moddone Aug 17 10:07:42 unbound[97431:0] info: validator operate: query webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] info: validator operate: chased to . TYPE0 CLASS0 Aug 17 10:07:42 unbound[97431:0] debug: verify: could not find appropriate key Aug 17 10:07:42 unbound[97431:0] info: validator: response has failed AUTHORITY rrset: harte-lyne.ca. SOA IN Aug 17 10:07:42 unbound[97431:0] info: Validate: message contains bad rrsets Aug 17 10:07:42 unbound[97431:0] debug: cache memory msg=136418 rrset=219879 infra=3130 val=98767 Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) Aug 17 10:07:42 unbound[97431:0] info: 127.0.0.1 webfax.harte-lyne.ca.harte-lyne.ca. A IN Aug 17 10:07:42 unbound[97431:0] debug: worker request: max UDP reply size modified (65535 to max-udp-size) This looks to me like a DNSSEC problem but it is not happening on other systems. If I visit another FreeBSD system on the same LAN running local_unbound then I see this result: $ sudo service local_unbound status Password: local_unbound is running as pid 561. $ ping webfax.harte-lyne.ca PING webfax.hamilton.harte-lyne.ca (216.185.71.105): 56 data bytes 64 bytes from 216.185.71.105: icmp_seq=0 ttl=64 time=0.283 ms 64 bytes from 216.185.71.105: icmp_seq=1 ttl=64 time=0.211 ms ^C --- webfax.hamilton.harte-lyne.ca ping statistics --- 2 packets transmitted, 2 packets received, 0.0% packet loss round-trip min/avg/max/stddev = 0.211/0.247/0.283/0.036 ms Both systems are running unbound-1.5.8 dated 26 Jan 2017. I have double and trebel checked the dnssec configuration for our domain (harte-lyne.ca) and it checks out all green at Verisign and drill on the affect host does not report any error: drill +dnssec +multi harte-lyne.ca ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 47323 ;; flags: qr aa rd ra ; QUERY: 1, ANSWER: 1, AUTHORITY: 4, ADDITIONAL: 4 ;; QUESTION SECTION: ;; harte-lyne.ca. IN A ;; ANSWER SECTION: harte-lyne.ca. 172800 IN A 216.185.71.167 ;; AUTHORITY SECTION: harte-lyne.ca. 172800 IN NS dns01.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns03.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns04.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns02.harte-lyne.ca. ;; ADDITIONAL SECTION: dns01.harte-lyne.ca. 172800 IN A 216.185.71.33 dns02.harte-lyne.ca. 172800 IN A 209.47.176.33 dns03.harte-lyne.ca. 172800 IN A 216.185.71.34 dns04.harte-lyne.ca. 172800 IN A 209.47.176.34 In fact on the affected system I can successfully drill for a dns response and the local resolver still will not resolve the target: $ drill +dnssec +multi webfax.harte-lyne.ca ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 8017 ;; flags: qr aa rd ra ; QUERY: 1, ANSWER: 2, AUTHORITY: 4, ADDITIONAL: 4 ;; QUESTION SECTION: ;; webfax.harte-lyne.ca. IN A ;; ANSWER SECTION: webfax.harte-lyne.ca. 172800 IN CNAME webfax.hamilton.harte-lyne.ca. webfax.hamilton.harte-lyne.ca. 172800 IN A 216.185.71.105 ;; AUTHORITY SECTION: harte-lyne.ca. 172800 IN NS dns01.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns02.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns04.harte-lyne.ca. harte-lyne.ca. 172800 IN NS dns03.harte-lyne.ca. ;; ADDITIONAL SECTION: dns01.harte-lyne.ca. 172800 IN A 216.185.71.33 dns02.harte-lyne.ca. 172800 IN A 209.47.176.33 dns03.harte-lyne.ca. 172800 IN A 216.185.71.34 dns04.harte-lyne.ca. 172800 IN A 209.47.176.34 ;; Query time: 0 msec ;; SERVER: 216.185.71.34 ;; WHEN: Thu Aug 17 10:21:22 2017 ;; MSG SIZE rcvd: 228 [byrnejb_hll@vhost04 ~]$ ping webfax.harte-lyne.ca ping: cannot resolve webfax.harte-lyne.ca: Host name lookup failure So what is going on? If I have a configuration issue with DNSSEC or with Unbound then I really need to discover what it is and fix it. Otherwise I am left with the unsettling alternative that there is a serious bug in unbound. What is really bothering me is that restarting local_unbound makes the problem go away. If this was a configuration issue then the problem should not disappear on a restart only to reoccur some time later. -- *** e-Mail is NOT a SECURE channel *** Do NOT transmit sensitive data via e-Mail Do NOT open attachments nor follow links sent by e-Mail James B. Byrne mailto:ByrneJB@Harte-Lyne.ca Harte & Lyne Limited http://www.harte-lyne.ca 9 Brockley Drive vox: +1 905 561 1241 Hamilton, Ontario fax: +1 905 561 0757 Canada L8E 3C3