Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

https-dns-proxy init'ed before network is available and fails to find bootstrap server(s) #19531

Closed
Ohfalderal opened this issue Oct 5, 2022 · 16 comments · Fixed by #19543
Closed

Comments

@Ohfalderal
Copy link

Maintainer: @stangri
Environment: mips_24kc, TP-Link Archer C7 v5, OpenWrt 21.02.3 r16554-1d4dea6d4f

Description: process(es) spawned (rc.d/S80https-dns-proxy) and init'ed before network connectivity is established and never retries to resolve the DoH server(s).

Wed Oct 5 03:20:18 2022 user.notice https-dns-proxy: Starting service ✓✓✓✓✓
Wed Oct 5 03:20:34 2022 daemon.notice netifd: Interface 'wan6' is now up

https-dns-proxy log -
N.B. 1664932820 = Wednesday, October 5, 2022 3:20:20

[W] 1664932820.360011 main.c:236 HTTP/3 is not supported by current libcurl
[W] 1664932820.553924 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1664932825.540907 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1664932826.933228 main.c:119 1F7B: Query received before bootstrapping is completed, discarding.
[W] 1664932826.934780 main.c:119 BA28: Query received before bootstrapping is completed, discarding.
[W] 1664932829.440642 main.c:119 5EF3: Query received before bootstrapping is completed, discarding.
[W] 1664932829.440736 main.c:119 E153: Query received before bootstrapping is completed, discarding.
[W] 1664932830.542426 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1664932832.942280 main.c:119 5EF3: Query received before bootstrapping is completed, discarding.
[W] 1664932832.942375 main.c:119 E153: Query received before bootstrapping is completed, discarding.
[W] 1664932835.444849 main.c:119 5EF3: Query received before bootstrapping is completed, discarding.
[W] 1664932835.444943 main.c:119 E153: Query received before bootstrapping is completed, discarding.
[W] 1664932835.542700 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1664932847.035168 main.c:119 C93C: Query received before bootstrapping is completed, discarding.
[W] 1664932850.959015 main.c:119 5EF3: Query received before bootstrapping is completed, discarding.
[W] 1664932850.959119 main.c:119 E153: Query received before bootstrapping is completed, discarding.
[W] 1664932892.431432 dns_poller.c:79 DNS lookup failed: Timeout while contacting DNS servers

@stangri
Copy link
Member

stangri commented Oct 5, 2022

Do you also have a WAN interface or just WAN6?

@Ohfalderal
Copy link
Author

Both. But only IPV6 bootstrap servers defined.

stangri added a commit to stangri/packages that referenced this issue Oct 7, 2022
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
stangri added a commit to stangri/packages that referenced this issue Oct 7, 2022
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
(cherry picked from commit 796a3dd)
@stangri
Copy link
Member

stangri commented Oct 7, 2022

@Ohfalderal If you could test the init script from the PRs above, I'd appreciate it. It should cause https-dns-proxy to be restarted on WAN6 changes and should alleviate the problem.

@Ohfalderal
Copy link
Author

Ohfalderal commented Oct 7, 2022

@stangri
A restart command was added to rc.local but a race condition exists and the restart is too early -

root@pWPW10-2:~# logread -ehttps-dns
Fri Oct  7 03:20:18 2022 user.notice https-dns-proxy: Starting service ✓✓✓✓
Fri Oct  7 03:20:28 2022 user.notice https-dns-proxy: Stopping service ✓
Fri Oct  7 03:20:35 2022 user.notice https-dns-proxy: Starting service ✓✓✓✓

root@pWPW10-2:~# logread -ewan6
Fri Oct  7 03:20:19 2022 daemon.notice netifd: Interface 'wan6' is enabled
Fri Oct  7 03:20:19 2022 daemon.notice netifd: Interface 'wan6' has link connectivity
Fri Oct  7 03:20:19 2022 daemon.notice netifd: Interface 'wan6' is setting up now
Fri Oct  7 03:20:34 2022 daemon.notice netifd: Interface 'wan6' is now up
Fri Oct  7 03:20:34 2022 user.notice firewall: Reloading firewall due to ifup of wan6 (br-lan)

Replaced init.d/https-dns-proxy.init and rebooted -

[root@pWPW10-0:~# logread -ehttps-
Fri Oct  7 09:28:15 2022 user.notice https-dns-proxy: Starting service ✓✓✓

root@pWPW10-0:~# logread -ewan6
Fri Oct  7 09:28:13 2022 daemon.notice netifd: Interface 'wan6' is enabled
Fri Oct  7 09:28:13 2022 daemon.notice netifd: Interface 'wan6' has link connectivity
Fri Oct  7 09:28:13 2022 daemon.notice netifd: Interface 'wan6' is setting up now
Fri Oct  7 09:28:28 2022 daemon.notice netifd: Interface 'wan6' is now up

Due to #19366 it is not possible to determine if the DoH servers are correctly initialised.

@stangri
Two (2) comments on the updated script -

  1. two (2) additional 'canary_domain' vars pointing to iCloud.com have been added
  2. when a DoH definition is removed from /etc/config/https-dns-proxy, it is not removed from /etc/config/dhcp leaving a DNSmasq -S (server=) definition with no listening process

N.B. - you may have noticed that the syslogs are from different APs. '-2' is 21.02 and '-0' is 22.03

@stangri stangri reopened this Oct 7, 2022
@stangri
Copy link
Member

stangri commented Oct 7, 2022

If you're willing to disable logging to test the boot up functionality, please try the init script from this commit.

The procd_boot_delay is how long (seconds) the service will wait after boot to start and procd_boot_timeout is how long the service will try to obtain the gateway for on start (seconds).

Please limit 1 (one) problem per issue.

1582130940 pushed a commit to 1582130940/OpenWrt-Lean-Packages that referenced this issue Nov 10, 2022
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt/packages#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
1582130940 pushed a commit to 1582130940/OpenWrt-Lean-Packages that referenced this issue Nov 10, 2022
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt/packages#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
stokito pushed a commit to stokito/packages that referenced this issue Dec 6, 2022
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
@Ohfalderal
Copy link
Author

@stangri - Was this comment intended for #19366?

@stangri
Copy link
Member

stangri commented Jan 17, 2023

@Ohfalderal yes, thank you, I'll move the comment.

On a related note, I'm testing this: stangri/source.openwrt.melmac.net@7402fdc

SibrenVasse pushed a commit to SibrenVasse/packages that referenced this issue Feb 26, 2023
* update to upstream version 2022-08-12
* add ca_certs_file option for CA certs file for curl
* add procd_add_interface_trigger for wan6 (hopefully fixes
  openwrt#19531)

Signed-off-by: Stan Grishin <stangri@melmac.ca>
(cherry picked from commit 796a3dd)
@stangri
Copy link
Member

stangri commented Mar 10, 2023

@Ohfalderal do you have a different experience now that the boot() has been reintroduced into the init script?

@Ohfalderal
Copy link
Author

@stangri it would appear that a race condition still exists -

[I] 1680312020.084969 main.c:219 Version 
[I] 1680312020.084997 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312020.109868 main.c:221 System c-ares: 1.17.2
[I] 1680312020.198467 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312020.278590 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312020.459098 dns_server.c:50 Listening on 127.0.0.1:5054
[I] 1680312020.594598 main.c:306 DNS polling initialized for 'anycast.uncensoreddns.org'
[W] 1680312020.607617 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312025.599352 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680312028.702133 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680312035.579330 main.c:219 Version 
[I] 1680312035.579355 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312035.579367 main.c:221 System c-ares: 1.17.2
[I] 1680312035.579432 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312035.579819 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312035.580129 dns_server.c:50 Listening on 127.0.0.1:5054
[I] 1680312035.580785 main.c:306 DNS polling initialized for 'anycast.uncensoreddns.org'
[W] 1680312035.581268 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312036.327527 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312036.329374 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836032 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836107 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836166 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836223 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[I] 1680312020.084599 main.c:219 Version 
[I] 1680312020.084626 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312020.107195 main.c:221 System c-ares: 1.17.2
[I] 1680312020.177537 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312020.297097 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312020.459286 dns_server.c:50 Listening on 127.0.0.1:5055
[I] 1680312020.593107 main.c:306 DNS polling initialized for 'dns.digitale-gesellschaft.ch'
[W] 1680312020.607261 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312025.598240 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680312028.702400 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680312035.572534 main.c:219 Version 
[I] 1680312035.572560 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312035.572571 main.c:221 System c-ares: 1.17.2
[I] 1680312035.572662 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312035.573036 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312035.573336 dns_server.c:50 Listening on 127.0.0.1:5055
[I] 1680312035.592603 main.c:306 DNS polling initialized for 'dns.digitale-gesellschaft.ch'
[W] 1680312035.593074 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312036.327391 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312036.329051 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835722 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835806 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835865 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835925 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[I] 1680312020.098176 main.c:219 Version 
[I] 1680312020.098202 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312020.112262 main.c:221 System c-ares: 1.17.2
[I] 1680312020.174854 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312020.282112 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312020.456535 dns_server.c:50 Listening on 127.0.0.1:5056
[I] 1680312020.590008 main.c:306 DNS polling initialized for 'secure.avastdns.com'
[W] 1680312020.615236 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312025.594273 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680312028.702648 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680312035.569305 main.c:219 Version 
[I] 1680312035.569330 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312035.569341 main.c:221 System c-ares: 1.17.2
[I] 1680312035.569434 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312035.590789 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312035.591124 dns_server.c:50 Listening on 127.0.0.1:5056
[I] 1680312035.591753 main.c:306 DNS polling initialized for 'secure.avastdns.com'
[W] 1680312035.592234 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312036.327225 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312036.328726 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835350 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835480 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835543 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.835600 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[I] 1680312020.084118 main.c:219 Version 
[I] 1680312020.084144 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312020.126532 main.c:221 System c-ares: 1.17.2
[I] 1680312020.198380 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312020.282641 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312020.458883 dns_server.c:50 Listening on 127.0.0.1:5053
[I] 1680312020.592912 main.c:306 DNS polling initialized for 'unicast.censurfridns.dk'
[W] 1680312020.614667 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312025.598791 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680312028.698157 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680312035.582549 main.c:219 Version 
[I] 1680312035.582574 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680312035.582586 main.c:221 System c-ares: 1.17.2
[I] 1680312035.582646 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680312035.583033 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680312035.583540 dns_server.c:50 Listening on 127.0.0.1:5053
[I] 1680312035.584497 main.c:306 DNS polling initialized for 'unicast.censurfridns.dk'
[W] 1680312035.584972 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680312036.327649 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312036.329693 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836328 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836405 main.c:119 6970: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836465 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.
[W] 1680312038.836524 main.c:119 5BF9: Query received before bootstrapping is completed, discarding.

@stangri
Copy link
Member

stangri commented Apr 1, 2023

@stangri it would appear that a race condition still exists -

Can you try adjusting the value of START=80 in the /etc/init.d/https-dns-proxy to something higher (up to 95)?

@Ohfalderal
Copy link
Author

@stangri ...done (restart @ 03:21 CEST so tomorrow an update)

But why not implement the initialisation on a hotplug trigger?

@stangri
Copy link
Member

stangri commented Apr 3, 2023

@stangri ...done (restart @ 03:21 CEST so tomorrow an update)

But why not implement the initialisation on a hotplug trigger?

There is a hotplug script and PROCD service trigger.

@Ohfalderal
Copy link
Author

@stangri increasing the startup delay provokes cURL errors -

[I] 1680744020.097449 main.c:219 Version 
[I] 1680744020.097475 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680744020.108069 main.c:221 System c-ares: 1.17.2
[I] 1680744020.195201 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680744020.335937 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680744020.472621 dns_server.c:50 Listening on 127.0.0.1:5056
[I] 1680744020.615864 main.c:306 DNS polling initialized for 'secure.avastdns.com'
[W] 1680744020.626428 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680744025.620346 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680744034.636663 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680744041.478599 main.c:219 Version 
[I] 1680744041.478624 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680744041.478635 main.c:221 System c-ares: 1.17.2
[I] 1680744041.478700 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680744041.479092 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680744041.497462 dns_server.c:50 Listening on 127.0.0.1:5056
[I] 1680744041.498109 main.c:306 DNS polling initialized for 'secure.avastdns.com'
[W] 1680745646.482313 https_client.c:348 A0AA: curl request failed with 0: No error
[W] 1680745646.482380 https_client.c:350 A0AA: curl error message: SSL_connect failed with error -308: error state on socket
[W] 1680745646.482403 https_client.c:377 A0AA: No response (probably connection has been closed or timed out)
[I] 1680745646.482423 https_client.c:504 A0AA: Response was faulty, skipping DNS reply.
[W] 1680747193.557491 https_client.c:501 817A: Request was aborted.
[W] 1680747193.557954 https_client.c:501 8F31: Request was aborted.
[W] 1680747193.558495 https_client.c:501 15B0: Request was aborted.
[W] 1680747193.559034 https_client.c:501 B447: Request was aborted.
[W] 1680747193.559570 https_client.c:501 4617: Request was aborted.
[W] 1680747193.560103 https_client.c:501 013B: Request was aborted.
[W] 1680747193.572927 https_client.c:501 817A: Request was aborted.
[W] 1680747193.573475 https_client.c:501 8F31: Request was aborted.
[W] 1680747193.574010 https_client.c:501 15B0: Request was aborted.
[W] 1680747193.585518 https_client.c:501 B447: Request was aborted.
[W] 1680754636.779388 https_client.c:501 48F7: Request was aborted.
[W] 1680754636.779916 https_client.c:501 6F3F: Request was aborted.
[W] 1680754636.796428 https_client.c:501 176D: Request was aborted.
[W] 1680754636.796988 https_client.c:501 48B2: Request was aborted.
[W] 1680754636.798889 https_client.c:501 C42F: Request was aborted.
[W] 1680756444.277278 https_client.c:348 1213: curl request failed with 0: No error
[W] 1680756444.277343 https_client.c:350 1213: curl error message: SSL_connect failed with error -308: error state on socket
[W] 1680756444.277366 https_client.c:377 1213: No response (probably connection has been closed or timed out)
[I] 1680756444.277387 https_client.c:504 1213: Response was faulty, skipping DNS reply.
[W] 1680757111.510783 https_client.c:348 DADD: curl request failed with 0: No error
[W] 1680757111.510849 https_client.c:350 DADD: curl error message: SSL_connect failed with error -308: error state on socket
[W] 1680757111.510872 https_client.c:377 DADD: No response (probably connection has been closed or timed out)
[I] 1680757111.510893 https_client.c:504 DADD: Response was faulty, skipping DNS reply.
[W] 1680757111.512209 https_client.c:348 7D1A: curl request failed with 0: No error
[W] 1680757111.512272 https_client.c:350 7D1A: curl error message: SSL_connect failed with error -308: error state on socket
[W] 1680757111.512294 https_client.c:377 7D1A: No response (probably connection has been closed or timed out)
[I] 1680757111.512315 https_client.c:504 7D1A: Response was faulty, skipping DNS reply.
[I] 1680744020.100966 main.c:219 Version 
[I] 1680744020.100994 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680744020.107953 main.c:221 System c-ares: 1.17.2
[I] 1680744020.199439 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680744020.332730 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680744020.475281 dns_server.c:50 Listening on 127.0.0.1:5054
[I] 1680744020.612826 main.c:306 DNS polling initialized for 'anycast.uncensoreddns.org'
[W] 1680744020.628241 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[W] 1680744025.615801 dns_poller.c:79 DNS lookup failed: Could not contact DNS servers
[I] 1680744034.635899 main.c:72 Shutting down gracefully. To force exit, send signal again.
[I] 1680744041.483079 main.c:219 Version 
[I] 1680744041.483104 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680744041.483116 main.c:221 System c-ares: 1.17.2
[I] 1680744041.483204 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680744041.493518 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680744041.493866 dns_server.c:50 Listening on 127.0.0.1:5054
[I] 1680744041.494494 main.c:306 DNS polling initialized for 'anycast.uncensoreddns.org'
[W] 1680744452.211731 https_client.c:348 59A7: curl request failed with 0: No error
[W] 1680744452.211788 https_client.c:350 59A7: curl error message: Operation timed out after 10569 milliseconds with 0 bytes received
[W] 1680744452.211811 https_client.c:377 59A7: No response (probably connection has been closed or timed out)
[I] 1680744452.211832 https_client.c:504 59A7: Response was faulty, skipping DNS reply.

But what is more interesting is when the logging level is raised from 2 to 4 the cURL errors do not occur (perhaps the build of cURL for the Archer Cn platform has logging enabled #19366?) -

[I] 1680617624.873145 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680617624.873157 main.c:221 System c-ares: 1.17.2
[I] 1680617624.873249 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680617624.873697 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680617624.874035 dns_server.c:50 Listening on 127.0.0.1:5054
[D] 1680617624.874105 logging.c:39 starting periodic log flush timer
[D] 1680617624.874564 dns_poller.c:178 Nameservers count: 2
[I] 1680617624.874590 main.c:306 DNS polling initialized for 'anycast.uncensoreddns.org'
[D] 1680617624.874684 dns_poller.c:114 Starting DNS query
[D] 1680617624.875002 dns_poller.c:41 Reserved new io event: 0x77ce75b0
[D] 1680617624.875205 dns_poller.c:126 DNS poll interval changed to: 0.700
[D] 1680617624.886481 main.c:185 Received new DNS server IP '2001:67c:28a4::'
[D] 1680617624.886729 dns_poller.c:88 DNS poll interval changed to: 120
[D] 1680617624.886794 dns_poller.c:31 Released used io event: 0x77ce75b0
[D] 1680617645.375631 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617645.375708 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617645.376307 https_client.c:77 curl opened socket: 9
[D] 1680617645.376776 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617645.380015 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617645.380086 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617645.380622 https_client.c:77 curl opened socket: 10
[D] 1680617645.381006 https_client.c:600 Reserved new io event: 0x7fa7b990
[D] 1680617645.381107 main.c:113 Received request for id: 2E58, len: 37
[D] 1680617645.381150 https_client.c:251 2E58: Requesting HTTP/2
[D] 1680617645.381706 https_client.c:77 curl opened socket: 11
[D] 1680617645.382082 https_client.c:600 Reserved new io event: 0x7fa7b9b0
[D] 1680617645.901111 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617645.901132 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617646.404592 https_client.c:590 Released used io event: 0x7fa7b990
[D] 1680617646.404649 https_client.c:600 Reserved new io event: 0x7fa7b990
[D] 1680617646.921612 https_client.c:590 Released used io event: 0x7fa7b9b0
[D] 1680617646.921633 https_client.c:600 Reserved new io event: 0x7fa7b9b0
[D] 1680617650.549011 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617650.549070 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617650.549530 https_client.c:77 curl opened socket: 12
[D] 1680617650.549907 https_client.c:600 Reserved new io event: 0x7fa7b9d0
[D] 1680617651.815779 https_client.c:590 Released used io event: 0x7fa7b9d0
[D] 1680617651.815800 https_client.c:600 Reserved new io event: 0x7fa7b9d0
[D] 1680617651.821894 https_client.c:205 CA9F: > POST /dns-query HTTP/2
[D] 1680617651.821928 https_client.c:205 CA9F: > Host: anycast.uncensoreddns.org
[D] 1680617651.821942 https_client.c:205 CA9F: > user-agent: https_dns_proxy/0.3
[D] 1680617651.821956 https_client.c:205 CA9F: > accept: application/dns-message
[D] 1680617651.821971 https_client.c:205 CA9F: > content-type: application/dns-message
[D] 1680617651.822022 https_client.c:205 CA9F: > content-length: 37
[D] 1680617651.822122 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617651.822137 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617651.828323 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617651.828356 https_client.c:205 6DD7: > Host: anycast.uncensoreddns.org
[D] 1680617651.828371 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617651.828385 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617651.828399 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617651.828413 https_client.c:205 6DD7: > content-length: 37
[D] 1680617651.828513 https_client.c:590 Released used io event: 0x7fa7b990
[D] 1680617651.828528 https_client.c:600 Reserved new io event: 0x7fa7b990
[D] 1680617651.828579 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617651.828651 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617651.829682 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617651.829790 https_client.c:205 6DD7: > Host: anycast.uncensoreddns.org
[D] 1680617651.829804 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617651.829819 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617651.829833 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617651.829847 https_client.c:205 6DD7: > content-length: 37
[D] 1680617651.835986 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617651.836158 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617651.839114 https_client.c:205 2E58: > POST /dns-query HTTP/2
[D] 1680617651.839147 https_client.c:205 2E58: > Host: anycast.uncensoreddns.org
[D] 1680617651.839161 https_client.c:205 2E58: > user-agent: https_dns_proxy/0.3
[D] 1680617651.839175 https_client.c:205 2E58: > accept: application/dns-message
[D] 1680617651.839189 https_client.c:205 2E58: > content-type: application/dns-message
[D] 1680617651.839203 https_client.c:205 2E58: > content-length: 37
[D] 1680617651.839349 https_client.c:590 Released used io event: 0x7fa7b9b0
[D] 1680617651.839365 https_client.c:600 Reserved new io event: 0x7fa7b9b0
[D] 1680617652.874800 https_client.c:590 Released used io event: 0x7fa7b990
[D] 1680617652.874829 https_client.c:600 Reserved new io event: 0x7fa7b990
[D] 1680617652.874882 main.c:113 Received request for id: 2E58, len: 37
[D] 1680617652.874929 https_client.c:251 2E58: Requesting HTTP/2
[D] 1680617652.883939 https_client.c:205 2E58: > POST /dns-query HTTP/2
[D] 1680617652.883973 https_client.c:205 2E58: > Host: anycast.uncensoreddns.org
[D] 1680617652.883988 https_client.c:205 2E58: > user-agent: https_dns_proxy/0.3
[D] 1680617652.884002 https_client.c:205 2E58: > accept: application/dns-message
[D] 1680617652.884016 https_client.c:205 2E58: > content-type: application/dns-message
[D] 1680617652.884031 https_client.c:205 2E58: > content-length: 37
[D] 1680617652.885055 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617652.885122 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617652.885596 https_client.c:590 Released used io event: 0x7fa7b9b0
[D] 1680617652.885625 https_client.c:600 Reserved new io event: 0x7fa7b9b0
[D] 1680617652.885949 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617652.886006 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617652.887415 https_client.c:205 CA9F: > POST /dns-query HTTP/2
[D] 1680617652.887448 https_client.c:205 CA9F: > Host: anycast.uncensoreddns.org
[D] 1680617652.887463 https_client.c:205 CA9F: > user-agent: https_dns_proxy/0.3
[D] 1680617652.887477 https_client.c:205 CA9F: > accept: application/dns-message
[D] 1680617652.887491 https_client.c:205 CA9F: > content-type: application/dns-message
[D] 1680617652.887505 https_client.c:205 CA9F: > content-length: 37
[D] 1680617652.888304 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617652.888333 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617652.897893 https_client.c:205 CA9F: > POST /dns-query HTTP/2
[D] 1680617652.897964 https_client.c:205 CA9F: > Host: anycast.uncensoreddns.org
[D] 1680617652.897979 https_client.c:205 CA9F: > user-agent: https_dns_proxy/0.3
[D] 1680617652.897993 https_client.c:205 CA9F: > accept: application/dns-message
[D] 1680617652.898007 https_client.c:205 CA9F: > content-type: application/dns-message
[D] 1680617652.898021 https_client.c:205 CA9F: > content-length: 37
[D] 1680617652.898122 https_client.c:590 Released used io event: 0x7fa7b9d0
[D] 1680617652.898137 https_client.c:600 Reserved new io event: 0x7fa7b9d0
[D] 1680617652.898337 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617652.898393 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617652.899969 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617652.900003 https_client.c:205 6DD7: > Host: anycast.uncensoreddns.org
[D] 1680617652.900018 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617652.900033 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617652.900124 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617652.900141 https_client.c:205 6DD7: > content-length: 37
[D] 1680617652.901013 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617652.901042 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617652.901613 https_client.c:590 Released used io event: 0x7fa7b970
[D] 1680617652.901642 https_client.c:600 Reserved new io event: 0x7fa7b970
[D] 1680617652.901778 https_client.c:205 6DD7: < HTTP/2 200 
[D] 1680617652.901804 https_client.c:205 6DD7: < server: h2o/dnsdist
[D] 1680617652.901830 https_client.c:205 6DD7: < date: Tue, 04 Apr 2023 14:14:11 GMT
[D] 1680617652.901857 https_client.c:205 6DD7: < strict-transport-security: max-age=31536000; includeSubDomains; preload
[D] 1680617652.901884 https_client.c:205 6DD7: < content-type: application/dns-message
[D] 1680617652.901906 https_client.c:205 6DD7: < cache-control: max-age=300
[D] 1680617652.901930 https_client.c:205 6DD7: < content-length: 88
[D] 1680617652.902133 https_client.c:341 6DD7: curl request succeeded
[D] 1680617652.902159 https_client.c:432 6DD7: CURLINFO_NUM_CONNECTS: 0
[D] 1680617652.902173 https_client.c:444 6DD7: CURLINFO_EFFECTIVE_URL: https://anycast.uncensoreddns.org/dns-query
[D] 1680617652.902188 https_client.c:450 6DD7: CURLINFO_HTTP_VERSION: 2
[D] 1680617652.902210 https_client.c:481 6DD7: Times: 0.000000, 0.000000, 0.000000, 0.001048, 0.001078, 1.073270
[D] 1680617652.902257 main.c:84 Received response for id: 6DD7, len: 88
[I] 1680617624.866105 main.c:219 Version 
[I] 1680617624.866131 main.c:220 Built Dec 17 2022 01:45:43.
[I] 1680617624.866142 main.c:221 System c-ares: 1.17.2
[I] 1680617624.866239 main.c:222 System libcurl: libcurl/7.83.1 wolfSSL/5.5.3 nghttp2/1.43.0
[W] 1680617624.866671 main.c:236 HTTP/3 is not supported by current libcurl
[I] 1680617624.867045 dns_server.c:50 Listening on 127.0.0.1:5053
[D] 1680617624.867139 logging.c:39 starting periodic log flush timer
[D] 1680617624.867635 dns_poller.c:178 Nameservers count: 2
[I] 1680617624.867662 main.c:306 DNS polling initialized for 'unicast.uncensoreddns.org'
[D] 1680617624.867762 dns_poller.c:114 Starting DNS query
[D] 1680617624.884959 dns_poller.c:41 Reserved new io event: 0x77c995b0
[D] 1680617624.885175 dns_poller.c:126 DNS poll interval changed to: 0.700
[D] 1680617624.898576 main.c:185 Received new DNS server IP '2a01:3a0:53:53::'
[D] 1680617624.898821 dns_poller.c:88 DNS poll interval changed to: 120
[D] 1680617624.898884 dns_poller.c:31 Released used io event: 0x77c995b0
[D] 1680617645.371534 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617645.371603 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617645.372227 https_client.c:77 curl opened socket: 9
[D] 1680617645.372706 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617645.382256 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617645.382326 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617645.382868 https_client.c:77 curl opened socket: 10
[D] 1680617645.383253 https_client.c:600 Reserved new io event: 0x7faab300
[D] 1680617645.383356 main.c:113 Received request for id: 2E58, len: 37
[D] 1680617645.383401 https_client.c:251 2E58: Requesting HTTP/2
[D] 1680617645.386986 https_client.c:77 curl opened socket: 11
[D] 1680617645.387357 https_client.c:600 Reserved new io event: 0x7faab320
[D] 1680617645.934287 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617645.934308 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617646.468436 https_client.c:590 Released used io event: 0x7faab300
[D] 1680617646.468494 https_client.c:600 Reserved new io event: 0x7faab300
[D] 1680617646.991647 https_client.c:590 Released used io event: 0x7faab320
[D] 1680617646.991668 https_client.c:600 Reserved new io event: 0x7faab320
[D] 1680617650.578775 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617650.578833 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617650.579295 https_client.c:77 curl opened socket: 12
[D] 1680617650.579674 https_client.c:600 Reserved new io event: 0x7faab340
[D] 1680617651.866215 https_client.c:590 Released used io event: 0x7faab340
[D] 1680617651.866236 https_client.c:600 Reserved new io event: 0x7faab340
[D] 1680617651.868312 https_client.c:205 CA9F: > POST /dns-query HTTP/2
[D] 1680617651.868345 https_client.c:205 CA9F: > Host: unicast.uncensoreddns.org
[D] 1680617651.868360 https_client.c:205 CA9F: > user-agent: https_dns_proxy/0.3
[D] 1680617651.868374 https_client.c:205 CA9F: > accept: application/dns-message
[D] 1680617651.868388 https_client.c:205 CA9F: > content-type: application/dns-message
[D] 1680617651.868440 https_client.c:205 CA9F: > content-length: 37
[D] 1680617651.868543 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617651.868557 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617651.870630 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617651.870663 https_client.c:205 6DD7: > Host: unicast.uncensoreddns.org
[D] 1680617651.870678 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617651.870692 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617651.870706 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617651.870720 https_client.c:205 6DD7: > content-length: 37
[D] 1680617651.870819 https_client.c:590 Released used io event: 0x7faab300
[D] 1680617651.870833 https_client.c:600 Reserved new io event: 0x7faab300
[D] 1680617651.870886 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617651.870935 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617651.879943 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617651.880055 https_client.c:205 6DD7: > Host: unicast.uncensoreddns.org
[D] 1680617651.880070 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617651.880084 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617651.880098 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617651.880112 https_client.c:205 6DD7: > content-length: 37
[D] 1680617651.880620 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617651.880649 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617651.882661 https_client.c:205 2E58: > POST /dns-query HTTP/2
[D] 1680617651.882694 https_client.c:205 2E58: > Host: unicast.uncensoreddns.org
[D] 1680617651.882708 https_client.c:205 2E58: > user-agent: https_dns_proxy/0.3
[D] 1680617651.882722 https_client.c:205 2E58: > accept: application/dns-message
[D] 1680617651.882736 https_client.c:205 2E58: > content-type: application/dns-message
[D] 1680617651.882750 https_client.c:205 2E58: > content-length: 37
[D] 1680617651.882887 https_client.c:590 Released used io event: 0x7faab320
[D] 1680617651.882902 https_client.c:600 Reserved new io event: 0x7faab320
[D] 1680617651.883456 https_client.c:590 Released used io event: 0x7faab300
[D] 1680617651.883484 https_client.c:600 Reserved new io event: 0x7faab300
[D] 1680617651.883538 main.c:113 Received request for id: 2E58, len: 37
[D] 1680617651.883633 https_client.c:251 2E58: Requesting HTTP/2
[D] 1680617651.888712 https_client.c:205 2E58: > POST /dns-query HTTP/2
[D] 1680617651.888744 https_client.c:205 2E58: > Host: unicast.uncensoreddns.org
[D] 1680617651.888758 https_client.c:205 2E58: > user-agent: https_dns_proxy/0.3
[D] 1680617651.888773 https_client.c:205 2E58: > accept: application/dns-message
[D] 1680617651.888787 https_client.c:205 2E58: > content-type: application/dns-message
[D] 1680617651.888801 https_client.c:205 2E58: > content-length: 37
[D] 1680617651.889287 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617651.889352 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617651.889818 https_client.c:590 Released used io event: 0x7faab320
[D] 1680617651.889847 https_client.c:600 Reserved new io event: 0x7faab320
[D] 1680617651.889965 main.c:113 Received request for id: CA9F, len: 37
[D] 1680617651.890044 https_client.c:251 CA9F: Requesting HTTP/2
[D] 1680617651.896401 https_client.c:205 CA9F: > POST /dns-query HTTP/2
[D] 1680617651.896435 https_client.c:205 CA9F: > Host: unicast.uncensoreddns.org
[D] 1680617651.896450 https_client.c:205 CA9F: > user-agent: https_dns_proxy/0.3
[D] 1680617651.896464 https_client.c:205 CA9F: > accept: application/dns-message
[D] 1680617651.896477 https_client.c:205 CA9F: > content-type: application/dns-message
[D] 1680617651.896491 https_client.c:205 CA9F: > content-length: 37
[D] 1680617651.896971 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617651.897001 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617651.897908 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617651.897976 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617652.922213 main.c:113 Received request for id: 6DD7, len: 37
[D] 1680617652.922269 https_client.c:251 6DD7: Requesting HTTP/2
[D] 1680617652.923442 https_client.c:205 6DD7: > POST /dns-query HTTP/2
[D] 1680617652.923476 https_client.c:205 6DD7: > Host: unicast.uncensoreddns.org
[D] 1680617652.923490 https_client.c:205 6DD7: > user-agent: https_dns_proxy/0.3
[D] 1680617652.923504 https_client.c:205 6DD7: > accept: application/dns-message
[D] 1680617652.923518 https_client.c:205 6DD7: > content-type: application/dns-message
[D] 1680617652.923532 https_client.c:205 6DD7: > content-length: 37
[D] 1680617652.924237 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617652.924265 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617652.925306 main.c:113 Received request for id: 2E58, len: 37
[D] 1680617652.925367 https_client.c:251 2E58: Requesting HTTP/2
[D] 1680617652.926454 https_client.c:205 2E58: > POST /dns-query HTTP/2
[D] 1680617652.926560 https_client.c:205 2E58: > Host: unicast.uncensoreddns.org
[D] 1680617652.926574 https_client.c:205 2E58: > user-agent: https_dns_proxy/0.3
[D] 1680617652.926588 https_client.c:205 2E58: > accept: application/dns-message
[D] 1680617652.926603 https_client.c:205 2E58: > content-type: application/dns-message
[D] 1680617652.926616 https_client.c:205 2E58: > content-length: 37
[D] 1680617652.927522 https_client.c:590 Released used io event: 0x7faab2e0
[D] 1680617652.927700 https_client.c:600 Reserved new io event: 0x7faab2e0
[D] 1680617652.927849 https_client.c:205 6DD7: < HTTP/2 200 
[D] 1680617652.927920 https_client.c:205 6DD7: < server: h2o/dnsdist
[D] 1680617652.927946 https_client.c:205 6DD7: < date: Tue, 04 Apr 2023 14:14:11 GMT
[D] 1680617652.927973 https_client.c:205 6DD7: < strict-transport-security: max-age=31536000; includeSubDomains; preload
[D] 1680617652.928001 https_client.c:205 6DD7: < content-type: application/dns-message
[D] 1680617652.928024 https_client.c:205 6DD7: < cache-control: max-age=300
[D] 1680617652.928094 https_client.c:205 6DD7: < content-length: 88
[D] 1680617652.928658 https_client.c:341 6DD7: curl request succeeded
[D] 1680617652.928692 https_client.c:432 6DD7: CURLINFO_NUM_CONNECTS: 0
[D] 1680617652.928706 https_client.c:444 6DD7: CURLINFO_EFFECTIVE_URL: https://unicast.uncensoreddns.org/dns-query
[D] 1680617652.928720 https_client.c:450 6DD7: CURLINFO_HTTP_VERSION: 2
[D] 1680617652.928743 https_client.c:481 6DD7: Times: 0.000000, 0.000000, 0.000000, 0.009007, 0.009040, 1.057400
[D] 1680617652.928791 main.c:84 Received response for id: 6DD7, len: 88

@stangri
Copy link
Member

stangri commented Sep 17, 2023

@Ohfalderal this PR: #22122 in combination with a previous one to stop service if resolution is not working on boot should address the issue.

@Ohfalderal
Copy link
Author

Ohfalderal commented Sep 18, 2023 via email

@stangri
Copy link
Member

stangri commented Sep 18, 2023

I'm closing this then.

@stangri stangri closed this as completed Sep 18, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants