Date: Thu, 17 Aug 2017 10:32:58 -0400 From: "James B. Byrne" <byrnejb@harte-lyne.ca> To: freebsd-questions@freebsd.org Subject: Re: FreeBSD-11 - local_unbound logging Message-ID: <7eeceea605f1c7e5d4a786822268e86d.squirrel@216.185.71.106> In-Reply-To: <d07d474ff8fa5689248708eaa62d506d.squirrel@webmail.harte-lyne.ca> References: <d07d474ff8fa5689248708eaa62d506d.squirrel@webmail.harte-lyne.ca>
next in thread | previous in thread | raw e-mail | index | archive | help
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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?7eeceea605f1c7e5d4a786822268e86d.squirrel>