Skip to content

fix: flakey test simple_node_id_based_connection_transfer#3534

Merged
ramfox merged 7 commits intomainfrom
ramfox/flakey-test-simple-node-id
Oct 20, 2025
Merged

fix: flakey test simple_node_id_based_connection_transfer#3534
ramfox merged 7 commits intomainfrom
ramfox/flakey-test-simple-node-id

Conversation

@ramfox
Copy link
Copy Markdown
Member

@ramfox ramfox commented Oct 14, 2025

Description

Breaking Changes

Notes & open questions

Change checklist

  • Self-review.
  • Documentation updates following the style guide, if relevant.
  • Tests if relevant.
  • All breaking changes documented.
    • List all breaking changes in the above "Breaking Changes" section.
    • Open an issue or PR on any number0 repos that are affected by this breaking change. Give guidance on how the updates should be handled or do the actual updates themselves. The major ones are:

@ramfox ramfox force-pushed the ramfox/flakey-test-simple-node-id branch from 0e2cfa7 to 8d9bc61 Compare October 14, 2025 03:13
@github-actions
Copy link
Copy Markdown

github-actions bot commented Oct 14, 2025 •
edited
Loading

Documentation for this PR has been generated and is available at: https://n0-computer.github.io/iroh/pr/3534/docs/iroh/

Last updated: 2025-10-20T19:44:06Z

@n0bot n0bot bot added this to iroh Oct 14, 2025
@github-project-automation github-project-automation bot moved this to 🏗 In progress in iroh Oct 14, 2025
@ramfox
Copy link
Copy Markdown
Member Author

ramfox commented Oct 14, 2025

simple_node_id flakey test update:

  • I can't get it to fail again, even when looping. The only failure I got was that the entire loop was running too long, not that a particular run failed
  • from looking at the previously gathered logs, it looks like each time it failed either a net-report hadn't run or QAD failed
  • The timeout occurs because we wait until we can successfully resolve the published node id and it has a relay url
  • Since we didn't run a successful net-report, we don't get a relay url and the loop timesout
  • I've added logging to make things clearer, but nothing has failed yet.
  • I'm going to keep the logging and add an endpoint.online() in a timeout for the endpoint with the id we need to resolve and hopefully that does enough to make sure we have a relay url before we check for resolution.

@ramfox ramfox force-pushed the ramfox/flakey-test-simple-node-id branch from 5c33804 to 8208190 Compare October 14, 2025 14:41
@github-actions
Copy link
Copy Markdown

github-actions bot commented Oct 14, 2025 •
edited
Loading

Netsim report & logs for this PR have been generated and is available at: LOGS
This report will remain available for 3 days.

Last updated for commit: e6f5826

@ramfox
Copy link
Copy Markdown
Member Author

ramfox commented Oct 14, 2025

Okay with the newest failures:

2025-10-14T14:50:37.211356Z DEBUG ep{me=e02535e1f3}: iroh::discovery::pkarr: creating pkarr publisher that publishes to https://staging-dns.iroh.link/pkarr
2025-10-14T14:50:37.212757Z DEBUG ep{me=e02535e1f3}: iroh::magicsock: binding addr=0.0.0.0:0
2025-10-14T14:50:37.213135Z DEBUG ep{me=e02535e1f3}: iroh::magicsock: successfully bound addr=0.0.0.0:0 local_addr=0.0.0.0:36815
2025-10-14T14:50:37.213287Z DEBUG ep{me=e02535e1f3}: iroh::magicsock: binding addr=[::]:36816
2025-10-14T14:50:37.213558Z DEBUG ep{me=e02535e1f3}: iroh::magicsock: successfully bound addr=[::]:36816 local_addr=[::]:36816
2025-10-14T14:50:37.220665Z DEBUG ep{me=e02535e1f3}:portmapper.service: portmapper: portmap starting
2025-10-14T14:50:37.226374Z DEBUG ep{me=e02535e1f3}:portmapper.service: portmapper: getting a port mapping for 5.9.119.203:36815 -> None
2025-10-14T14:50:37.226959Z DEBUG ep{me=e02535e1f3}:portmapper.service:upnp: igd_next::aio::tokio: sending broadcast request to: 239.255.255.250:1900 on interface: Ok(0.0.0.0:40544)
2025-10-14T14:50:37.228116Z DEBUG ep{me=e02535e1f3}: iroh::magicsock: scheduling periodic_stun to run immediately and in 20s
2025-10-14T14:50:37.228447Z DEBUG ep{me=e02535e1f3}: iroh::_events::direct_addrs: addrs={DirectAddr { addr: 5.9.119.203:36815, typ: Local }, DirectAddr { addr: 172.17.0.1:36815, typ: Local }, DirectAddr { addr: [2a01:4f8:162:64cd::2]:36816, typ: Local }}
2025-10-14T14:50:37.228876Z DEBUG ep{me=e02535e1f3}: iroh::endpoint: iroh Endpoint created version="0.93.2"
2025-10-14T14:50:37.229166Z  INFO integration: started client node id e02535e1f3
2025-10-14T14:50:37.232453Z DEBUG ep{me=96c6240b66}: iroh::discovery::pkarr: creating pkarr publisher that publishes to https://staging-dns.iroh.link/pkarr
2025-10-14T14:50:37.232976Z DEBUG ep{me=96c6240b66}: iroh::magicsock: binding addr=0.0.0.0:0
2025-10-14T14:50:37.233274Z DEBUG ep{me=96c6240b66}: iroh::magicsock: successfully bound addr=0.0.0.0:0 local_addr=0.0.0.0:55474
2025-10-14T14:50:37.233423Z DEBUG ep{me=96c6240b66}: iroh::magicsock: binding addr=[::]:55475
2025-10-14T14:50:37.233704Z DEBUG ep{me=96c6240b66}: iroh::magicsock: successfully bound addr=[::]:55475 local_addr=[::]:55475
2025-10-14T14:50:37.240108Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: iroh::discovery::pkarr: Publish node info to pkarr (info changed)
2025-10-14T14:50:37.240290Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: iroh::discovery::pkarr: Publish node info to pkarr data=NodeData { relay_url: None, direct_addresses: {5.9.119.203:36815, 172.17.0.1:36815, [2a01:4f8:162:64cd::2]:36816}, user_data: None } pkarr_relay=https://staging-dns.iroh.link/pkarr
2025-10-14T14:50:37.243158Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: reqwest::connect: starting new connection: https://staging-dns.iroh.link/
2025-10-14T14:50:37.244082Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::xfer::dns_handle: querying: staging-dns.iroh.link. A
2025-10-14T14:50:37.244389Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_resolver::name_server::name_server_pool: sending request: [Query { name: Name("staging-dns.iroh.link."), query_type: A, query_class: IN }]
2025-10-14T14:50:37.244775Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_resolver::name_server::name_server: reconnecting: NameServerConfig { socket_addr: 127.0.0.53:53, protocol: Udp, tls_dns_name: None, http_endpoint: None, trust_negative_responses: false, bind_addr: None }
2025-10-14T14:50:37.245082Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::xfer: enqueueing message:QUERY:[Query { name: Name("staging-dns.iroh.link."), query_type: A, query_class: IN }]
2025-10-14T14:50:37.245561Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::xfer::dns_handle: querying: staging-dns.iroh.link. AAAA
2025-10-14T14:50:37.245784Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_resolver::name_server::name_server_pool: sending request: [Query { name: Name("staging-dns.iroh.link."), query_type: AAAA, query_class: IN }]
2025-10-14T14:50:37.246027Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_resolver::name_server::name_server: existing connection: NameServerConfig { socket_addr: 127.0.0.53:53, protocol: Udp, tls_dns_name: None, http_endpoint: None, trust_negative_responses: false, bind_addr: None }
2025-10-14T14:50:37.246189Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::xfer: enqueueing message:QUERY:[Query { name: Name("staging-dns.iroh.link."), query_type: AAAA, query_class: IN }]
2025-10-14T14:50:37.246788Z DEBUG ep{me=96c6240b66}:portmapper.service: portmapper: portmap starting
2025-10-14T14:50:37.252339Z DEBUG ep{me=96c6240b66}:portmapper.service: portmapper: getting a port mapping for 5.9.119.203:55474 -> None
2025-10-14T14:50:37.252899Z DEBUG hickory_proto::udp::udp_client_stream: final message: ; header 3304:QUERY:RD:NoError:QUERY:0/0/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 1232 opts: 0
; query
;; staging-dns.iroh.link. IN A

2025-10-14T14:50:37.253182Z DEBUG hickory_proto::udp::udp_client_stream: final message: ; header 43776:QUERY:RD:NoError:QUERY:0/0/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 1232 opts: 0
; query
;; staging-dns.iroh.link. IN AAAA
; answers 1
staging-euw1-1.relay.iroh.network. 127 IN AAAA 2a01:4f8:c0c:a493::1
; nameservers 0
; additionals 1

2025-10-14T14:50:37.298279Z DEBUG ep{me=e02535e1f3}:actor:QAD-IPv6{relay_url=https://staging-euw1-1.relay.iroh.network./}: iroh::net_report: relay addr v6 relay_addr_orig=[2a01:4f8:c0c:a493::1]:7842 relay_addr=[fd15:70a:510b:1::2]:12345
2025-10-14T14:50:37.298616Z DEBUG ep{me=e02535e1f3}:actor:QAD-IPv6{relay_url=https://staging-euw1-1.relay.iroh.network./}: rustls::client::hs: No cached session for DnsName("staging-euw1-1.relay.iroh.network.")
2025-10-14T14:50:37.298773Z DEBUG ep{me=e02535e1f3}:actor:QAD-IPv6{relay_url=https://staging-euw1-1.relay.iroh.network./}: rustls::client::hs: Not resuming any session
2025-10-14T14:50:37.300946Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hickory_proto::udp::udp_client_stream: received message id: 13753
2025-10-14T14:50:37.301161Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hickory_proto::error: response: ; header 13753:RESPONSE:RD,RA:NoError:QUERY:0/1/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 65494 opts: 0
; query
;; staging-dns.iroh.link. IN AAAA
; answers 0
; nameservers 1
staging-dns.iroh.link. 60 IN SOA staging-dns.iroh.link. hostmaster.staging-dns.iroh.link. 1 7200 900 1209600 3
; additionals 1

2025-10-14T14:50:43.660695Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hickory_proto::udp::udp_client_stream: received message id: 64909
2025-10-14T14:50:43.660873Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hickory_proto::error: response: ; header 64909:RESPONSE:RD,RA:NoError:QUERY:1/0/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 65494 opts: 0
; query
;; staging-dns.iroh.link. IN A
; answers 1
staging-dns.iroh.link. 3140 IN A 49.13.237.105
; nameservers 0
; additionals 1

2025-10-14T14:50:43.661066Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hickory_proto::error: response: ; header 64909:RESPONSE:RD,RA:NoError:QUERY:1/0/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 65494 opts: 0
; query
;; staging-dns.iroh.link. IN A
; answers 1
staging-dns.iroh.link. 3140 IN A 49.13.237.105
; nameservers 0
; additionals 1

2025-10-14T14:50:43.661646Z DEBUG ep{me=96c6240b66}:pkarr_publish{me=96c6240b66}: hyper_util::client::legacy::connect::http: connecting to 49.13.237.105:443
2025-10-14T14:50:43.662394Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::udp::udp_client_stream: received message id: 43776
2025-10-14T14:50:43.662509Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hickory_proto::error: response: ; header 43776:RESPONSE:RD,RA:NoError:QUERY:0/1/1
; edns version: 0 dnssec_ok: false z_flags: 0 max_payload: 65494 opts: 0
; query
;; staging-dns.iroh.link. IN AAAA
; answers 0
; nameservers 1
staging-dns.iroh.link. 60 IN SOA staging-dns.iroh.link. hostmaster.staging-dns.iroh.link. 1 7200 900 1209600 3
; additionals 1

2025-10-14T14:50:43.665643Z DEBUG ep{me=e02535e1f3}:pkarr_publish{me=e02535e1f3}: hyper_util::client::legacy::connect::http: connecting to 49.13.237.105:443

@ramfox
Copy link
Copy Markdown
Member Author

ramfox commented Oct 14, 2025

After checking the relay server logs, it looks like there is never a connection made to the relay server from the endpoints in the tests.

@ramfox ramfox force-pushed the ramfox/flakey-test-simple-node-id branch from b5eef74 to 25ec296 Compare October 15, 2025 16:08
@ramfox ramfox added this to the v0.94 milestone Oct 20, 2025
@ramfox ramfox force-pushed the ramfox/flakey-test-simple-node-id branch 2 times, most recently from 1e193ea to 9b84cd2 Compare October 20, 2025 19:02
@ramfox ramfox merged commit 0f86c38 into main Oct 20, 2025
29 checks passed
@github-project-automation github-project-automation bot moved this from 🏗 In progress to ✅ Done in iroh Oct 20, 2025
@ramfox ramfox deleted the ramfox/flakey-test-simple-node-id branch October 20, 2025 19:57
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

None yet

Projects

iroh
Status: ✅ Done

Milestone

v0.94

Development

Successfully merging this pull request may close these issues.

1 participant

@ramfox