resolution of `mail.comcast.com MX` fails

respdiff suggests it should succeed.

I haven't looked closely into this, but from the surface it looks related to #626 and #659.

Log from 63d02c44.

[00000.00][plan] plan 'mail.comcast.net.' type 'MX' uid [46333.00]
[46333.00][iter]   'mail.comcast.net.' type 'MX' new uid was assigned .01, parent uid .00
[46333.01][cach]   => no NSEC* cached for zone: net.
[46333.01][cach]   => skipping zone: net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.01][cach]   => skipping zone: net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.01][zcut]   found cut: net. (rank 002 return codes: DS 0, DNSKEY 0)
[46333.01][resl]   => id: '15433' querying: '2001:503:eea3::30#00053' score: 79 zone cut: 'net.' qname: 'CoMCAst.neT.' qtype: 'NS' proto: 'udp'
[46333.01][iter]   <= loaded 10 glue addresses
[46333.01][iter]   <= referral response, follow
[46333.01][vldr]   <= DS: OK
[46333.01][vldr]   <= answer valid, OK
[46333.01][cach]   => stashed comcast.net. DS, rank 060, 264 B total, incl. 1 RRSIGs
[46333.01][cach]   => stashed comcast.net. NS, rank 002, 124 B total, incl. 0 RRSIGs
[46333.01][cach]   => stashed also 10 nonauth RRsets
[46333.01][resl]   <= server: '2001:503:eea3::30' rtt: 43 ms
[46333.01][iter]   'mail.comcast.net.' type 'MX' new uid was assigned .02, parent uid .00
[46333.02][plan]   plan 'comcast.net.' type 'DNSKEY' uid [46333.03]
[46333.03][iter]     'comcast.net.' type 'DNSKEY' new uid was assigned .04, parent uid .02
[46333.04][cach]     => no NSEC* cached for zone: comcast.net.
[46333.04][cach]     => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.04][cach]     => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.04][resl]     => id: '01302' querying: '2001:558:1014:c:68:87:76:228#00053' score: 10 zone cut: 'comcast.net.' qname: 'COMcasT.neT.' qtype: 'DNSKEY' proto: 'udp'
[46333.04][iter]     <= rcode: NOERROR
[46333.04][vldr]     <= parent: updating DNSKEY
[46333.04][vldr]     <= answer valid, OK
[46333.04][cach]     => stashed comcast.net. DNSKEY, rank 060, 870 B total, incl. 2 RRSIGs
[46333.04][resl]     <= server: '2001:558:1014:c:68:87:76:228' rtt: 191 ms
[46333.02][iter]   'mail.comcast.net.' type 'MX' new uid was assigned .05, parent uid .00
[46333.05][resl]   => id: '50780' querying: '68.87.76.228#00053' score: 10 zone cut: 'comcast.net.' qname: 'MaIL.COmCAST.Net.' qtype: 'MX' proto: 'udp'
[46333.05][iter]   <= rcode: NOERROR
[46333.05][iter]   <= cname chain, following
[00000.00][plan] plan 'imap.ge.xfinity.com.' type 'MX' uid [46333.06]
[46333.05][vldr]   <= answer valid, OK
[46333.05][cach]   => stashed mail.comcast.net. CNAME, rank 060, 200 B total, incl. 1 RRSIGs
[46333.05][resl]   <= server: '68.87.76.228' rtt: 194 ms
[46333.06][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .07, parent uid .00
[46333.07][cach]   => trying zone: ., NSEC, hash 0
[46333.07][cach]   => NSEC sname: range search miss (!covers)
[46333.07][cach]   => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
[46333.07][zcut]   found cut: . (rank 060 return codes: DS -2, DNSKEY 0)
[46333.07][resl]   >< TA: '.'
[46333.07][resl]   => id: '16802' querying: '2001:500:12::d0d#00053' score: 53 zone cut: '.' qname: 'Com.' qtype: 'NS' proto: 'udp'
[46333.07][iter]   <= loaded 26 glue addresses
[46333.07][iter]   <= referral response, follow
[46333.07][vldr]   <= DS: OK
[46333.07][vldr]   <= answer valid, OK
[46333.07][cach]   => stashed com. DS, rank 060, 330 B total, incl. 1 RRSIGs
[46333.07][cach]   => stashed com. NS, rank 002, 300 B total, incl. 0 RRSIGs
[46333.07][cach]   => not overwriting AAAA a.gtld-servers.net.
[46333.07][cach]   => not overwriting A a.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA e.gtld-servers.net.
[46333.07][cach]   => not overwriting A e.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA h.gtld-servers.net.
[46333.07][cach]   => not overwriting A h.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA k.gtld-servers.net.
[46333.07][cach]   => not overwriting A k.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA m.gtld-servers.net.
[46333.07][cach]   => not overwriting A m.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA g.gtld-servers.net.
[46333.07][cach]   => not overwriting A g.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA i.gtld-servers.net.
[46333.07][cach]   => not overwriting A i.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA c.gtld-servers.net.
[46333.07][cach]   => not overwriting A c.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA f.gtld-servers.net.
[46333.07][cach]   => not overwriting A f.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA d.gtld-servers.net.
[46333.07][cach]   => not overwriting A d.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA b.gtld-servers.net.
[46333.07][cach]   => not overwriting A b.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA j.gtld-servers.net.
[46333.07][cach]   => not overwriting A j.gtld-servers.net.
[46333.07][cach]   => not overwriting AAAA l.gtld-servers.net.
[46333.07][cach]   => not overwriting A l.gtld-servers.net.
[46333.07][resl]   <= server: '2001:500:12::d0d' rtt: 53 ms
[46333.07][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .08, parent uid .00
[46333.08][plan]   plan 'com.' type 'DNSKEY' uid [46333.09]
[46333.09][iter]     'com.' type 'DNSKEY' new uid was assigned .10, parent uid .08
[46333.10][cach]     => no NSEC* cached for zone: com.
[46333.10][cach]     => skipping zone: com., NSEC, hash 0;new TTL -123456789, ret -2
[46333.10][cach]     => skipping zone: com., NSEC, hash 0;new TTL -123456789, ret -2
[46333.10][resl]     => id: '64293' querying: '2001:503:83eb::30#00053' score: 72 zone cut: 'com.' qname: 'cOM.' qtype: 'DNSKEY' proto: 'udp'
[46333.10][iter]     <= rcode: NOERROR
[46333.10][vldr]     <= parent: updating DNSKEY
[46333.10][vldr]     <= answer valid, OK
[46333.10][cach]     => stashed com. DNSKEY, rank 060, 730 B total, incl. 1 RRSIGs
[46333.10][resl]     <= server: '2001:503:83eb::30' rtt: 46 ms
[46333.08][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .11, parent uid .00
[46333.11][resl]   => id: '12580' querying: '2001:502:8cc::30#00053' score: 44 zone cut: 'com.' qname: 'xFiNiTy.COm.' qtype: 'NS' proto: 'udp'
[46333.11][iter]   <= referral response, follow
[46333.11][vldr]   <= DS: OK
[46333.11][vldr]   <= answer valid, OK
[46333.11][cach]   => stashed xfinity.com. DS, rank 060, 264 B total, incl. 1 RRSIGs
[46333.11][cach]   => stashed xfinity.com. NS, rank 002, 124 B total, incl. 0 RRSIGs
[46333.11][resl]   <= server: '2001:502:8cc::30' rtt: 45 ms
[46333.11][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .12, parent uid .00
[46333.12][plan]   plan 'xfinity.com.' type 'DNSKEY' uid [46333.13]
[46333.13][iter]     'xfinity.com.' type 'DNSKEY' new uid was assigned .14, parent uid .12
[46333.14][cach]     => no NSEC* cached for zone: xfinity.com.
[46333.14][cach]     => skipping zone: xfinity.com., NSEC, hash 0;new TTL -123456789, ret -2
[46333.14][cach]     => skipping zone: xfinity.com., NSEC, hash 0;new TTL -123456789, ret -2
[46333.14][plan]     plan 'dns103.comcast.net.' type 'AAAA' uid [46333.15]
[46333.15][iter]       'dns103.comcast.net.' type 'AAAA' new uid was assigned .16, parent uid .14
[46333.16][cach]       => satisfied by exact RRset: rank 001, new TTL 172800
[46333.16][iter]       <= rcode: NOERROR
[46333.14][iter]     'xfinity.com.' type 'DNSKEY' new uid was assigned .17, parent uid .12
[46333.17][resl]     => id: '36870' querying: '2001:558:1014:c:68:87:76:228#00053' score: 191 zone cut: 'xfinity.com.' qname: 'XFINiTY.coM.' qtype: 'DNSKEY' proto: 'udp'
[46333.17][iter]     <= rcode: NOERROR
[46333.17][vldr]     <= parent: updating DNSKEY
[46333.17][vldr]     <= answer valid, OK
[46333.17][cach]     => stashed xfinity.com. DNSKEY, rank 060, 870 B total, incl. 2 RRSIGs
[46333.17][resl]     <= server: '2001:558:1014:c:68:87:76:228' rtt: 193 ms
[46333.12][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .18, parent uid .00
[46333.18][plan]   plan 'dns104.comcast.net.' type 'AAAA' uid [46333.19]
[46333.19][iter]     'dns104.comcast.net.' type 'AAAA' new uid was assigned .20, parent uid .18
[46333.20][cach]     => satisfied by exact RRset: rank 001, new TTL 172800
[46333.20][iter]     <= rcode: NOERROR
[46333.18][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .21, parent uid .00
[46333.21][resl]   => id: '58082' querying: '2001:558:100a:5:68:87:68:244#00053' score: 10 zone cut: 'xfinity.com.' qname: 'ge.xFINIty.CoM.' qtype: 'NS' proto: 'udp'
[46333.21][iter]   <= referral response, follow
[46333.21][vldr]   <= answer valid, OK
[46333.21][cach]   => stashed ge.xfinity.com. NSEC, rank 060, 210 B total, incl. 1 RRSIGs
[46333.21][cach]   => stashed ge.xfinity.com. NS, rank 010, 188 B total, incl. 0 RRSIGs
[46333.21][cach]   => nsec_p stashed for xfinity.com. (new, hash: 0)
[46333.21][resl]   <= server: '2001:558:100a:5:68:87:68:244' rtt: 144 ms
[46333.21][iter]   'imap.ge.xfinity.com.' type 'MX' new uid was assigned .22, parent uid .00
[46333.22][resl]   <= DS doesn't exist, going insecure
[46333.22][plan]   plan 'gtd03-d.hillsboro.or.ndchlsbr.comcast.net.' type 'AAAA' uid [46333.23]
[46333.23][iter]     'gtd03-d.hillsboro.or.ndchlsbr.comcast.net.' type 'AAAA' new uid was assigned .24, parent uid .22
[46333.24][cach]     => no NSEC* cached for zone: comcast.net.
[46333.24][cach]     => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.24][cach]     => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.24][zcut]     found cut: comcast.net. (rank 002 return codes: DS 0, DNSKEY 0)
[46333.24][resl]     => id: '62333' querying: '2001:558:1004:7:68:87:85:132#00053' score: 10 zone cut: 'comcast.net.' qname: 'NdchLsbR.CoMCAST.nEt.' qtype: 'NS' proto: 'udp'
[46333.24][iter]     <= rcode: NOERROR
[46333.24][iter]     <= retrying with non-minimized name
[46333.24][resl]     <= server: '2001:558:1004:7:68:87:85:132' rtt: 165 ms
[46333.24][iter]     'gtd03-d.hillsboro.or.ndchlsbr.comcast.net.' type 'AAAA' new uid was assigned .25, parent uid .22
[46333.25][resl]     => id: '33890' querying: '2001:558:fe23:8:69:252:250:103#00053' score: 10 zone cut: 'comcast.net.' qname: 'GTD03-D.HiLLsBoRO.OR.ndChLsbR.cOMCASt.NET.' qtype: 'AAAA' proto: 'udp'
[46333.25][iter]     <= rcode: NOERROR
[46333.25][vldr]     >< cut changed, needs revalidation
[46333.25][resl]     <= server: '2001:558:fe23:8:69:252:250:103' rtt: 127 ms
[46333.25][resl]     => resuming yielded answer
[46333.25][vldr]     >< no valid RRSIGs found: gtd03-d.hillsboro.or.ndchlsbr.comcast.net. AAAA (0 matching RRSIGs, 0 expired, 0 not yet valid, 0 invalid signer, 0 invalid label count, 0 invalid key, 0 invalid crypto, 0 invalid NSEC)
[46333.25][plan]     plan 'ndchlsbr.comcast.net.' type 'DS' uid [46333.26]
[46333.26][iter]       'ndchlsbr.comcast.net.' type 'DS' new uid was assigned .27, parent uid .25
[46333.27][cach]       => no NSEC* cached for zone: comcast.net.
[46333.27][cach]       => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.27][cach]       => skipping zone: comcast.net., NSEC, hash 0;new TTL -123456789, ret -2
[46333.27][resl]       => id: '63949' querying: '2001:558:100e:5:68:87:72:244#00053' score: 10 zone cut: 'comcast.net.' qname: 'ndchLsbr.COMCAST.net.' qtype: 'DS' proto: 'udp'
[46333.27][iter]       <= rcode: NOERROR
[46333.27][vldr]       <= parent: updating DS
[46333.27][vldr]       <= answer valid, OK
[46333.27][cach]       => stashed northlake.il.ndchgo.comcast.net. NSEC, rank 060, 222 B total, incl. 1 RRSIGs
[46333.27][cach]       => stashed comcast.net. SOA, rank 060, 248 B total, incl. 1 RRSIGs
[46333.27][cach]       => nsec_p stashed for comcast.net. (new, hash: 0)
[46333.27][resl]       <= server: '2001:558:100e:5:68:87:72:244' rtt: 146 ms
[46333.25][resl]     => resuming yielded answer
[46333.25][vldr]     >< no valid RRSIGs found: gtd03-d.hillsboro.or.ndchlsbr.comcast.net. AAAA (0 matching RRSIGs, 0 expired, 0 not yet valid, 0 invalid signer, 0 invalid label count, 0 invalid key, 0 invalid crypto, 0 invalid NSEC)
[46333.25][plan]     plan 'ndchlsbr.comcast.net.' type 'DS' uid [46333.28]
[46333.28][iter]       'ndchlsbr.comcast.net.' type 'DS' new uid was assigned .29, parent uid .25
[46333.29][cach]       => trying zone: comcast.net., NSEC, hash 0
[46333.29][cach]       => NSEC sname: covered by: northlake.il.ndchgo.comcast.net. -> hillsboro.or.ndchlsbr.comcast.net., new TTL 3600
[46333.29][cach]       => NSEC sname: empty non-terminal by the same RR
[46333.29][iter]       <= rcode: NOERROR
[46333.29][vldr]       <= parent: updating DS
[46333.29][vldr]       <= answer valid, OK
[46333.25][resl]     => resuming yielded answer
[46333.25][vldr]     >< no valid RRSIGs found: gtd03-d.hillsboro.or.ndchlsbr.comcast.net. AAAA (0 matching RRSIGs, 0 expired, 0 not yet valid, 0 invalid signer, 0 invalid label count, 0 invalid key, 0 invalid crypto, 0 invalid NSEC)
[46333.25][vldr]     <= continuous revalidation, fails
[46333.25][cach]     => stashed gtd03-d.hillsboro.or.ndchlsbr.comcast.net. AAAA, rank 027, 32 B total, incl. 0 RRSIGs
[46333.25][cach]     => not overwriting AAAA gtd03-d.hillsboro.or.ndchlsbr.comcast.net.
[46333.00][resl] request failed, answering with empty SERVFAIL
[46333.25][resl]     finished in state: 8, queries: 8, mempool: 65600 B

The life test case is NXDOMAIN now, so the error can't be reproduced anymore.

We can probably close this; it seems like an another case of Resolver getting failing on >< cut changed, needs revalidation with <= continuous revalidation, fails after switching off query minimization.

closed