Skip site navigation (1)Skip section navigation (2)
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: <http://docs.FreeBSD.org/cgi/mid.cgi?7eeceea605f1c7e5d4a786822268e86d.squirrel>