search

openwrt / packages

Community maintained packages for OpenWrt. Documentation for submitting pull requests is in CONTRIBUTING.md
GNU General Public License v2.0
3.95k stars 3.46k forks source link

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

Closed Ohfalderal closed 1 year ago

Ohfalderal commented 1 year ago

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 commented 1 year ago

Do you also have a WAN interface or just WAN6?

Ohfalderal commented 1 year ago

Both. But only IPV6 bootstrap servers defined.

stangri commented 1 year ago

@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 commented 1 year ago

@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 commented 1 year ago

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.

Ohfalderal commented 1 year ago

@stangri - Was this comment intended for #19366?

stangri commented 1 year ago

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

On a related note, I'm testing this: https://github.com/stangri/source.openwrt.melmac.net/commit/7402fdcd02bdae1e1699a58cb659c961e6b551c8

stangri commented 1 year ago

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

Ohfalderal commented 1 year ago

@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 commented 1 year ago

@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 commented 1 year ago

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

But why not implement the initialisation on a hotplug trigger?

stangri commented 1 year ago

@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 commented 1 year ago

@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 commented 1 year ago

@Ohfalderal this PR: https://github.com/openwrt/packages/pull/22122 in combination with a previous one to stop service if resolution is not working on boot should address the issue.

Ohfalderal commented 1 year ago

I added a 'service https-dns-proxy restart' to rc.local .

On Sun, 17 Sept 2023, 03:59 Stan Grishin, @.***> wrote:

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

— Reply to this email directly, view it on GitHub https://github.com/openwrt/packages/issues/19531#issuecomment-1722367616, or unsubscribe https://github.com/notifications/unsubscribe-auth/A3JNOAKRE3EZ4GXI5ZZIXCLX2ZKPHANCNFSM6AAAAAAQ5MIY4I . You are receiving this because you were mentioned.Message ID: @.***>

stangri commented 1 year ago

I'm closing this then.