#1001 Multiple faults in 0.10 DNS resolution

Reporter ge0rg
Owner MattJ
Created
Updated
Stars ★★ (2)  
Tags
  • Status-Fixed
  • Type-Defect
  • Priority-Medium
  • Milestone-0.10
  1. ge0rg on

    This is probably a duplicate of #487 and maybe others, but I'd like to collect some evidence here, so please bear with me. It all started out with the Conversations MUC switching servers. From my log file, early on - the SRV and DNS resolution fails (conference.siacs.eu is a CNAME, so this is #487): Sep 23 06:27:23 c2s179f9980 debug Received[c2s]: <iq id='7725a77d-710d-4f0a-bec4-e3f388bdc7d4' type='get' to='conference.siacs.eu'> Sep 23 06:27:23 stanzarouter debug Routing to remote... Sep 23 06:27:23 mod_s2s debug opening a new outgoing connection for this stanza Sep 23 06:27:23 mod_s2s debug stanza [iq] queued until connection complete Sep 23 06:27:23 mod_s2s debug First attempt to connect to conference.siacs.eu, starting with SRV lookup... Sep 23 06:27:23 adns debug Records for _xmpp-server._tcp.conference.siacs.eu. not in cache, sending query (thread: 0xf4e90a0)... Sep 23 06:27:23 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 06:27:23 adns debug Reply for _xmpp-server._tcp.conference.siacs.eu. (thread: 0xf4e90a0) Sep 23 06:27:23 mod_s2s debug conference.siacs.eu has no SRV records, falling back to A/AAAA Sep 23 06:27:23 adns debug Records for conference.siacs.eu not in cache, sending query (thread: 0x17f7fd20)... Sep 23 06:27:23 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 06:27:23 adns debug Records for conference.siacs.eu not in cache, sending query (thread: 0x137948a0)... Sep 23 06:27:23 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 06:27:23 adns debug Reply for conference.siacs.eu (thread: 0x137948a0) Sep 23 06:27:23 adns debug Reply for conference.siacs.eu (thread: 0x17f7fd20) Sep 23 06:27:23 mod_s2s debug DNS lookup failed to get a response for conference.siacs.eu Sep 23 06:27:23 s2sout1bb2ac00 info Failed in all attempts to connect to conference.siacs.eu Sep 23 06:27:23 mod_s2s debug No other records to try for conference.siacs.eu - destroying Sep 23 06:27:23 s2sout1bb2ac00 debug Destroying outgoing session yax.im->conference.siacs.eu: DNS resolution failed Sep 23 06:27:23 s2sout1bb2ac00 info Sending error replies for 1 queued stanzas because of failed outgoing connection to conference.siacs.eu That happens a bunch of times over the morning and afternoon... However, there are funny things happening at least once: Sep 23 10:14:52 stanzarouter debug Routing to remote... Sep 23 10:14:52 s2soute3245b0 debug trying to send over unauthed s2sout to conference.siacs.eu Sep 23 10:14:52 s2soute3245b0 debug stanza [presence] queued Sep 23 10:14:52 adns debug Reply for _xmpp-server._tcp.conference.siacs.eu. (thread: 0xa6c6eb0) Sep 23 10:14:52 mod_s2s debug conference.siacs.eu has no SRV records, falling back to A/AAAA Sep 23 10:14:52 adns debug Records for conference.siacs.eu already cached, using those... Sep 23 10:14:52 mod_s2s debug DNS reply for conference.siacs.eu gives us 78.47.217.197 Sep 23 10:14:52 adns debug Records for conference.siacs.eu not in cache, sending query (thread: 0x146585e0)... Sep 23 10:14:52 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 10:14:52 adns debug Reply for conference.siacs.eu (thread: 0x146585e0) Sep 23 10:14:52 s2soute3245b0 debug Beginning new connection attempt to conference.siacs.eu ([78.47.217.197]:5269) [...] Sep 23 10:14:52 s2soute3245b0 info Session closed by remote with error: host-unknown (This host does not serve conference.siacs.eu) What the what? Sep 23 10:22:00 s2soutd0a07d0 debug Beginning new connection attempt to conference.siacs.eu ([78.47.217.197]:5269) Sep 23 10:22:00 s2soutd0a07d0 debug sending: <?xml version='1.0'?> Sep 23 10:22:00 s2soutd0a07d0 debug sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='yax.im' to='conference.siacs.eu' version='1.0' xmlns='jabber:server'> Sep 23 10:22:00 s2soutd0a07d0 debug s2s connection attempt failed: closed Sep 23 10:22:00 s2soutd0a07d0 info Failed in all attempts to connect to conference.siacs.eu Sep 23 10:22:00 s2soutd0a07d0 debug Destroying outgoing session yax.im->conference.siacs.eu: Connecting failed: closed Sep 23 10:22:00 s2soutd0a07d0 info Sending error replies for 1 queued stanzas because of failed outgoing connection to conference.siacs.eu Sep 23 10:22:00 s2soutd0a07d0 debug s2s disconnected: nil->nil (closed) However, by virtue of pure black magic, after I was asked to run dns:cache() (which didn't yield results for the host in question), the connection magically worked: Sep 23 18:07:47 mod_s2s debug conference.siacs.eu has no SRV records, falling back to A/AAAA Sep 23 18:07:47 adns debug Records for conference.siacs.eu not in cache, sending query (thread: 0x195c4900)... Sep 23 18:07:47 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 18:07:47 adns debug Records for conference.siacs.eu not in cache, sending query (thread: 0x62c5290)... Sep 23 18:07:47 adns debug Sending DNS query to 2a01:30:2000:100::66 Sep 23 18:07:47 adns debug Reply for conference.siacs.eu (thread: 0x62c5290) Sep 23 18:07:47 adns debug Reply for conference.siacs.eu (thread: 0x195c4900) Sep 23 18:07:47 mod_s2s debug DNS reply for conference.siacs.eu gives us 91.250.85.114 Sep 23 18:07:47 s2sout1e1a9600 debug Beginning new connection attempt to conference.siacs.eu ([91.250.85.114]:5269) Sep 23 18:07:47 mod_s2s debug Connection attempt in progress... Sep 23 18:07:47 socket debug new connection established. id: 17520690 Sep 23 18:07:47 s2sout1e1a9600 debug sending: <?xml version='1.0'?> Sep 23 18:07:47 s2sout1e1a9600 debug sending: <stream:stream xmlns:db='jabber:server:dialback' xmlns:stream='http://etherx.jabber.org/streams' xml:lang='en' from='yax.im' to='conference.siacs.eu' version='1.0' xmlns='jabber:server'> [...] connection yax.im->conference.siacs.eu complete Sep 23 18:07:47 mod_admin_web debug Added host conference.siacs.eu s2sout Sep 23 18:07:47 s2sout1e1a9600 debug sending 2 queued stanzas across new outgoing connection to conference.siacs.eu

  2. ge0rg on

    11:53:55 daniel> Ge0rG, we switched over on friday at ~23:45 11:54:12 daniel> i don't think i've touched the records since

  3. MattJ on

    I've pushed https://hg.prosody.im/0.10/rev/42fad8465537 which should be in nightly 430+ Please let me know if you find any issues after this, otherwise I'll assume we fixed it and close this issue.

    Changes
    • tags Status-Accepted
    • owner MattJ
  4. MattJ on

    Changes
    • tags Milestone-0.10
  5. MattJ on

    Changes
    • tags Status-NeedInfo
  6. MattJ on

    It's been a month since the fix was committed, so I'm going to close this. Feel free to open a new ticket for specific DNS issues encountered from now on.

    Changes
    • tags Status-Fixed

New comment