Skip to content

DEBUG3 gives cluttered output #111

@matsduf

Description

@matsduf

Up to and including DEBUG2 messages are single line. DEBUG3 includes something that looks like dig output, which is multiline. That make reading the output hard. Next is an excerpt from the following command, zonemaster-cli --level=DEBUG3 --test=CONSISTENCY/consistency05 --show_module iis.se:

   0.09 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=202.12.27.33; name=m.root-servers.net
   0.10 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:0dc3:0000:0000:0000:0000:0000:0035; name=m.root-servers.net
   0.10 DEBUG2    SYSTEM       SYSTEM:RECURSE_QUERY address=2001:0dc3:0000:0000:0000:0000:0000:0035; class=IN; name=iis.se; ns=m.root-servers.net; source=m.root-servers.net/2001:dc3::35; type=SOA
   0.10 DEBUG2    SYSTEM       SYSTEM:QUERY flags={"class":"IN"}; ip=2001:dc3::35; name=iis.se; type=SOA
   0.10 DEBUG2    SYSTEM       SYSTEM:CACHE_CREATED ip=2001:0dc3:0000:0000:0000:0000:0000:0035
   0.11 DEBUG2    SYSTEM       SYSTEM:CACHE_FETCHED ip=2001:0dc3:0000:0000:0000:0000:0000:0035
   0.11 DEBUG     SYSTEM       SYSTEM:EXTERNAL_QUERY flags={"class":"IN"}; ip=2001:dc3::35; name=iis.se; type=SOA
   0.15 DEBUG3    SYSTEM       SYSTEM:EXTERNAL_RESPONSE packet=;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 55847
;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 10, ADDITIONAL: 15 
;; QUESTION SECTION:
;; iis.se.      IN      SOA

;; ANSWER SECTION:

;; AUTHORITY SECTION:
se.     172800  IN      NS      z.ns.se.
se.     172800  IN      NS      x.ns.se.
se.     172800  IN      NS      y.ns.se.
se.     172800  IN      NS      j.ns.se.
se.     172800  IN      NS      a.ns.se.
se.     172800  IN      NS      c.ns.se.
se.     172800  IN      NS      f.ns.se.
se.     172800  IN      NS      g.ns.se.
se.     172800  IN      NS      i.ns.se.
se.     172800  IN      NS      b.ns.se.

;; ADDITIONAL SECTION:
a.ns.se.        172800  IN      A       192.36.144.107
b.ns.se.        172800  IN      A       192.36.133.107
c.ns.se.        172800  IN      A       192.36.135.107
f.ns.se.        172800  IN      A       192.71.53.53
g.ns.se.        172800  IN      A       130.239.5.114
i.ns.se.        172800  IN      A       194.146.106.22
j.ns.se.        172800  IN      A       199.254.63.1
x.ns.se.        172800  IN      A       213.108.25.4
y.ns.se.        172800  IN      A       185.159.197.150
z.ns.se.        172800  IN      A       185.159.198.150
a.ns.se.        172800  IN      AAAA    2a01:3f0:0:301::53
b.ns.se.        172800  IN      AAAA    2001:67c:254c:301::53
c.ns.se.        172800  IN      AAAA    2001:67c:2554:301::53
f.ns.se.        172800  IN      AAAA    2a01:3f0:0:305::53
g.ns.se.        172800  IN      AAAA    2001:6b0:e:3::1

;; Query time: 36 msec
;; SERVER: 2001:dc3::35
;; WHEN: Mon Jul 29 14:17:23 2019
;; MSG SIZE  rcvd: 487
   0.15 DEBUG3    SYSTEM       SYSTEM:CACHED_RETURN packet=;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 55847
;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 10, ADDITIONAL: 15 
;; QUESTION SECTION:
;; iis.se.      IN      SOA

;; ANSWER SECTION:

;; AUTHORITY SECTION:
se.     172800  IN      NS      z.ns.se.
se.     172800  IN      NS      x.ns.se.
se.     172800  IN      NS      y.ns.se.
se.     172800  IN      NS      j.ns.se.
se.     172800  IN      NS      a.ns.se.
se.     172800  IN      NS      c.ns.se.
se.     172800  IN      NS      f.ns.se.
se.     172800  IN      NS      g.ns.se.
se.     172800  IN      NS      i.ns.se.
se.     172800  IN      NS      b.ns.se.

;; ADDITIONAL SECTION:
a.ns.se.        172800  IN      A       192.36.144.107
b.ns.se.        172800  IN      A       192.36.133.107
c.ns.se.        172800  IN      A       192.36.135.107
f.ns.se.        172800  IN      A       192.71.53.53
g.ns.se.        172800  IN      A       130.239.5.114
i.ns.se.        172800  IN      A       194.146.106.22
j.ns.se.        172800  IN      A       199.254.63.1
x.ns.se.        172800  IN      A       213.108.25.4
y.ns.se.        172800  IN      A       185.159.197.150
z.ns.se.        172800  IN      A       185.159.198.150
a.ns.se.        172800  IN      AAAA    2a01:3f0:0:301::53
b.ns.se.        172800  IN      AAAA    2001:67c:254c:301::53
c.ns.se.        172800  IN      AAAA    2001:67c:2554:301::53
f.ns.se.        172800  IN      AAAA    2a01:3f0:0:305::53
g.ns.se.        172800  IN      AAAA    2001:6b0:e:3::1

;; Query time: 36 msec
;; SERVER: 2001:dc3::35
;; WHEN: Mon Jul 29 14:17:23 2019
;; MSG SIZE  rcvd: 487
   0.15 DEBUG2    SYSTEM       SYSTEM:IS_REDIRECT name="iis.se"; to="se"; type=SOA
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.144.107; name=a.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2a01:03f0:0000:0301:0000:0000:0000:0053; name=a.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.133.107; name=b.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:067c:254c:0301:0000:0000:0000:0053; name=b.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.135.107; name=c.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:067c:2554:0301:0000:0000:0000:0053; name=c.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.71.53.53; name=f.ns.se

Each "dig output" above belongs to the previous message, but the delimitation is hard to see. Also note that the first line of the "dig output" is presented at the end of the log message line. I propose the following format for "dig messages". Note the line break before the first line of the "dig message":

   0.09 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=202.12.27.33; name=m.root-servers.net
   0.10 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:0dc3:0000:0000:0000:0000:0000:0035; name=m.root-servers.net
   0.10 DEBUG2    SYSTEM       SYSTEM:RECURSE_QUERY address=2001:0dc3:0000:0000:0000:0000:0000:0035; class=IN; name=iis.se; ns=m.root-servers.net; source=m.root-servers.net/2001:dc3::35; type=SOA
   0.10 DEBUG2    SYSTEM       SYSTEM:QUERY flags={"class":"IN"}; ip=2001:dc3::35; name=iis.se; type=SOA
   0.10 DEBUG2    SYSTEM       SYSTEM:CACHE_CREATED ip=2001:0dc3:0000:0000:0000:0000:0000:0035
   0.11 DEBUG2    SYSTEM       SYSTEM:CACHE_FETCHED ip=2001:0dc3:0000:0000:0000:0000:0000:0035
   0.11 DEBUG     SYSTEM       SYSTEM:EXTERNAL_QUERY flags={"class":"IN"}; ip=2001:dc3::35; name=iis.se; type=SOA
   0.15 DEBUG3    SYSTEM       SYSTEM:EXTERNAL_RESPONSE packet=
                               ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 55847
                               ;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 10, ADDITIONAL: 15 
                               ;; QUESTION SECTION:
                               ;; iis.se.      IN      SOA

                               ;; ANSWER SECTION:

                               ;; AUTHORITY SECTION:
                               se.     172800  IN      NS      z.ns.se.
                               se.     172800  IN      NS      x.ns.se.
                               se.     172800  IN      NS      y.ns.se.
                               se.     172800  IN      NS      j.ns.se.
                               se.     172800  IN      NS      a.ns.se.
                               se.     172800  IN      NS      c.ns.se.
                               se.     172800  IN      NS      f.ns.se.
                               se.     172800  IN      NS      g.ns.se.
                               se.     172800  IN      NS      i.ns.se.
                               se.     172800  IN      NS      b.ns.se.
                               
                               ;; ADDITIONAL SECTION:
                               a.ns.se.        172800  IN      A       192.36.144.107
                               b.ns.se.        172800  IN      A       192.36.133.107
                               c.ns.se.        172800  IN      A       192.36.135.107
                               f.ns.se.        172800  IN      A       192.71.53.53
                               g.ns.se.        172800  IN      A       130.239.5.114
                               i.ns.se.        172800  IN      A       194.146.106.22
                               j.ns.se.        172800  IN      A       199.254.63.1
                               x.ns.se.        172800  IN      A       213.108.25.4
                               y.ns.se.        172800  IN      A       185.159.197.150
                               z.ns.se.        172800  IN      A       185.159.198.150
                               a.ns.se.        172800  IN      AAAA    2a01:3f0:0:301::53
                               b.ns.se.        172800  IN      AAAA    2001:67c:254c:301::53
                               c.ns.se.        172800  IN      AAAA    2001:67c:2554:301::53
                               f.ns.se.        172800  IN      AAAA    2a01:3f0:0:305::53
                               g.ns.se.        172800  IN      AAAA    2001:6b0:e:3::1
                               
                               ;; Query time: 36 msec
                               ;; SERVER: 2001:dc3::35
                               ;; WHEN: Mon Jul 29 14:17:23 2019
                               ;; MSG SIZE  rcvd: 487
   0.15 DEBUG3    SYSTEM       SYSTEM:CACHED_RETURN packet=
                               ;; ->>HEADER<<- opcode: QUERY, rcode: NOERROR, id: 55847
                               ;; flags: qr ; QUERY: 1, ANSWER: 0, AUTHORITY: 10, ADDITIONAL: 15 
                               ;; QUESTION SECTION:
                               ;; iis.se.      IN      SOA
                               
                               ;; ANSWER SECTION:
                               
                               ;; AUTHORITY SECTION:
                               se.     172800  IN      NS      z.ns.se.
                               se.     172800  IN      NS      x.ns.se.
                               se.     172800  IN      NS      y.ns.se.
                               se.     172800  IN      NS      j.ns.se.
                               se.     172800  IN      NS      a.ns.se.
                               se.     172800  IN      NS      c.ns.se.
                               se.     172800  IN      NS      f.ns.se.
                               se.     172800  IN      NS      g.ns.se.
                               se.     172800  IN      NS      i.ns.se.
                               se.     172800  IN      NS      b.ns.se.
                               
                               ;; ADDITIONAL SECTION:
                               a.ns.se.        172800  IN      A       192.36.144.107
                               b.ns.se.        172800  IN      A       192.36.133.107
                               c.ns.se.        172800  IN      A       192.36.135.107
                               f.ns.se.        172800  IN      A       192.71.53.53
                               g.ns.se.        172800  IN      A       130.239.5.114
                               i.ns.se.        172800  IN      A       194.146.106.22
                               j.ns.se.        172800  IN      A       199.254.63.1
                               x.ns.se.        172800  IN      A       213.108.25.4
                               y.ns.se.        172800  IN      A       185.159.197.150
                               z.ns.se.        172800  IN      A       185.159.198.150
                               a.ns.se.        172800  IN      AAAA    2a01:3f0:0:301::53
                               b.ns.se.        172800  IN      AAAA    2001:67c:254c:301::53
                               c.ns.se.        172800  IN      AAAA    2001:67c:2554:301::53
                               f.ns.se.        172800  IN      AAAA    2a01:3f0:0:305::53
                               g.ns.se.        172800  IN      AAAA    2001:6b0:e:3::1
                               
                               ;; Query time: 36 msec
                               ;; SERVER: 2001:dc3::35
                               ;; WHEN: Mon Jul 29 14:17:23 2019
                               ;; MSG SIZE  rcvd: 487
   0.15 DEBUG2    SYSTEM       SYSTEM:IS_REDIRECT name="iis.se"; to="se"; type=SOA
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.144.107; name=a.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2a01:03f0:0000:0301:0000:0000:0000:0053; name=a.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.133.107; name=b.ns.se
   0.16 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:067c:254c:0301:0000:0000:0000:0053; name=b.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.36.135.107; name=c.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=2001:067c:2554:0301:0000:0000:0000:0053; name=c.ns.se
   0.17 DEBUG2    SYSTEM       SYSTEM:NS_CREATED ip=192.71.53.53; name=f.ns.se

Metadata

Metadata

Assignees

No one assigned

    Labels

    T-FeatureType: New feature in software or test case description

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions