<html>
  <head>
    <meta http-equiv="Content-Type" content="text/html; charset=utf-8">
  </head>
  <body text="#000000" bgcolor="#FFFFFF">
    <p>For the next person who might hit this situation:</p>
    <p>The problem ultimately ended up being a misconfiguration on my
      side. Specifically, to work around some issues with 1-to-1 NAT I
      had seen previously, I had added records for my router local IP
      addresses to the 'supermasters' table on the slaves, the idea
      being that reflected NAT requests would come from those IPs.
      Little did I know, however, that PowerDNS will actually try to
      send the SOA requests for pending NOTIFY'd zones to the IPs listed
      in the 'supermasters' table, rather than actually resolve the A
      records of the NS records. This explains the intermittent
      behaviour - sometimes it would pick the right IP, other times it
      would pick the router IP, and of course the router address
      wouldn't respond to the SOA request. I hadn't actually seen this
      in my packet captures however because I was filtering specifically
      for the master IP address, and of course the SOA request packets
      destined for the router IP wouldn't show up there!<br>
    </p>
    <p>After removing the bad entries in the supermasters table, I'm no
      longer seeing either the reflected NAT issue, nor my inconsistent
      AXFRs, so I'd consider this solved. Thanks specifically to Habbie
      on IRC #powerdns who helped point me in the right direction
      (specifically that SOA requests happened before AXFRs so I knew
      what I was looking for).<br>
    </p>
    <p>Let this be a warning to anyone else trying a similar setup
      behind NAT!<br>
    </p>
    Thanks,<br>
    Joshua Boniface<br>
    <br>
    <div class="moz-cite-prefix">On 2017-09-06 6:12 PM, Joshua M.
      Boniface wrote:<br>
    </div>
    <blockquote type="cite"
      cite="mid:a9e21e62-9d7f-c0ed-39b0-e67e8620f1b6@boniface.me">
      <meta http-equiv="content-type" content="text/html; charset=utf-8">
      <p>Hello list!</p>
      <p>I'm experiencing a problem with my PowerDNS slave machines not
        performing AXFRs when notified by the master of a zone reload,
        and I've been unable to find any satisfactory answers. First,
        some of the pertinent questions:<br>
      </p>
      <ul>
        <li>What PowerDNS or dnsdist version you are using<br>
          <i>PowerDNS 4.0.3</i><br>
        </li>
        <li>What backends you use (gMySQL, BIND etc)<br>
          <i>gMySQL</i><br>
        </li>
        <li>If you are using DNSSEC<br>
          <i>Yes, the zones in question are signed on the master</i><br>
        </li>
        <li>Operating system it is running on<br>
          <i>Debian Stretch (9.1)</i><br>
        </li>
        <li>Where you got the binary from, i.e. did you compile it
          yourself (which compiler, including version), from your
          distribution or ports tree etc<br>
          <i>Using version from official Debian Stretch repositories</i><br>
        </li>
      </ul>
      <p>The specific problem I'm having can be summed up by the
        following two log lines on the slave:</p>
      <p>> Sep 06 14:31:33 2 slave domains need checking, 0 queued
        for AXFR<br>
        > Sep 06 14:31:36 Received serial number updates for 0 zones,
        had 2 timeouts</p>
      <p>I am triggering updates via the DHCP DDNS facility documented
        here:
        <a class="moz-txt-link-freetext"
href="https://doc.powerdns.com/md/authoritative/dnsupdate/#dns-update-how-to-setup-dyndnsrfc2136-with-dhcpd"
          moz-do-not-send="true">https://doc.powerdns.com/md/authoritative/dnsupdate/#dns-update-how-to-setup-dyndnsrfc2136-with-dhcpd</a>,
        however this problem also occurs occasionally though less
        frequently when I manually update a zone in the MySQL backend
        and trigger a "pdnsutil increase-serial <domain>" followed
        by a "pdns_control reload <domain>". This is occurring
        with many domains as well, though due to the DHCP DDNS I'm
        focusing on only two.<br>
      </p>
      <p>I would expect zero timeouts, however at least 50% of the time
        both relevant zone transfers time out as shown in the log above.
        40% of the time one times out, and only 10% of the time (based
        on about two dozen tests) do both zones AXFR as expected on both
        slave hosts. The timeout time is always exactly 3 seconds after
        the NOTIFY is received, and I've not found any setting in the
        documentation to increase this time.<br>
      </p>
      <p>I did a packet capture on both sides of the transaction (both
        master and slave), and I see the NOTIFY packet sent by the
        master and acknowledged on the slave, however when I see the
        timeouts I never see the slave send any sort of AXFR request as
        I would expect. The notifies are received without error to both
        hosts every time. Given the lack of relevant information in
        these I have not included them.<br>
      </p>
      <p>There is no firewalling or other network interruptions between
        the master and slave and they are on the same broadcast domain.
        And as mentioned, sometimes at least one domain succeeds and I
        see the AXFR request sent from the slave to the master. This
        occurs intermittently between both of my slave machines, so this
        does not appear to be network related. I also confirmed that
        there are no errors related to the MySQL backend on the master.<br>
      </p>
      <p>Increasing the loglevel to 9+ on both sides does not reveal any
        further information as to the timeout. So ultimately, my
        question is: <b>[tl;dr]</b> What exactly does "had X timeouts"
        mean on the slave (i.e. what is timing out), and what can I do
        to diagnose the cause or prevent it from happening?<br>
      </p>
      <p>Here is the full log from the master with loglevel=9 (with the
        main domain changed here to `domain.tld` for privacy purposes;
        as previously mentioned this is occurring for multiple domains
        anyways) for a sample run. In this particular case, my second
        slave server (10.9.0.66) properly responded with AXFR requests
        for both updated domains, however the first slave server
        (10.9.0.65) did not. This is fairly consistent behaviour for me
        regarding this problem - sometimes the first responds with one
        or both, other times the second responds, but almost invariably
        one zone on one host does not AXFR.<br>
      </p>
      <p>> Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep
        06 14:31:33 2 domains for which we are master need notifications<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Queued notification of domain 'i.domain.tld' to
        10.9.0.65:53<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Queued notification of domain 'i.domain.tld' to
        10.9.0.66:53<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Queued notification of domain '0.9.10.in-addr.arpa' to
        10.9.0.65:53<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Queued notification of domain '0.9.10.in-addr.arpa' to
        10.9.0.66:53<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 gmysql Connection successful. Connected to database
        'dns' on 'db.domain.tld'. [3 repetitions removed]<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Remote 10.9.0.66 wants '0.9.10.in-addr.arpa|SOA', do =
        1, bufsize = 1680: packetcache MISS<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Remote 10.9.0.66 wants 'i.domain.tld|SOA', do = 0,
        bufsize = 512: packetcache MISS<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain '0.9.10.in-addr.arpa' initiated by
        10.9.0.66<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain '0.9.10.in-addr.arpa' allowed: client IP
        10.9.0.66 is in allow-axfr-ips<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain 'i.domain.tld' initiated by 10.9.0.66<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain 'i.domain.tld' allowed: client IP
        10.9.0.66 is in allow-axfr-ips<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 gmysql Connection successful. Connected to database
        'dns' on 'db.domain.tld'. [10 repetitions removed]<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain 'i.domain.tld' to 10.9.0.66 finished<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 gmysql Connection successful. Connected to database
        'dns' on 'db.domain.tld'.<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 Done signing: 6425.07 sigs/s,<br>
        > Sep 06 14:31:33 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:33 AXFR of domain '0.9.10.in-addr.arpa' to 10.9.0.66
        finished<br>
        > Sep 06 14:31:34 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:34 Removed from notification list: 'i.domain.tld' to
        10.9.0.65:53 (was acknowledged)<br>
        > Sep 06 14:31:34 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:34 Removed from notification list: 'i.domain.tld' to
        10.9.0.66:53 (was acknowledged)<br>
        > Sep 06 14:31:34 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:34 Removed from notification list: '0.9.10.in-addr.arpa'
        to 10.9.0.65:53 (was acknowledged)<br>
        > Sep 06 14:31:34 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:34 Removed from notification list: '0.9.10.in-addr.arpa'
        to 10.9.0.66:53 (was acknowledged)<br>
        > Sep 06 14:31:36 dns.i.domain.tld pdns_server[30635]: Sep 06
        14:31:36 No master domains need notifications</p>
      <p>I appreciate any information or advice anyone can provide, and
        I am able to reproduce this consistently should more testing be
        required!</p>
      <p>Thanks,<br>
        Joshua Boniface<br>
      </p>
      <br>
      <fieldset class="mimeAttachmentHeader"></fieldset>
      <br>
      <pre wrap="">_______________________________________________
Pdns-users mailing list
<a class="moz-txt-link-abbreviated" href="mailto:Pdns-users@mailman.powerdns.com">Pdns-users@mailman.powerdns.com</a>
<a class="moz-txt-link-freetext" href="https://mailman.powerdns.com/mailman/listinfo/pdns-users">https://mailman.powerdns.com/mailman/listinfo/pdns-users</a>
</pre>
    </blockquote>
    <br>
  </body>
</html>