openwrt / packages

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

https-dns-proxy: Crash loop without apparent cause #22463

Closed Ryan-Goldstein closed 1 year ago

Ryan-Goldstein commented 1 year ago

Maintainer: @stangri Environment: OpenWrt 23.05.0 / mediatek/mt7622 / Belkin RT3200 UBI Customized image built using the Firmware Selector:

I created a thread on the OpenWrt Forum and, despite friendly guidance from and troubleshooting with @stangri in that thread, got stuck trying to determine the cause of a persistent crash loop of https-dns-proxy.

The output of each Troubleshooting command is as follows:

service log restart; service dnsmasq restart; service https-dns-proxy restart

udhcpc: started, v1.36.1
udhcpc: broadcasting discover
udhcpc: no lease, failing
Starting https-dns-proxy 2023-05-25-7 instances ✓

logread -e dnsmasq; netstat -l -n -p | grep -e dnsmasq

Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: started, version 2.89 cachesize 150
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: DNS service limited to local subnets
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: compile time options: IPv6 GNU-getopt no-DBus UBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-nftset no-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: UBus support enabled: connected to system bus
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq-dhcp[1]: DHCP, IP range 192.168.5.100 -- 192.168.5.249, lease time 12h
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using nameserver 127.0.0.1#5053
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: read /etc/hosts - 12 names
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 9 names
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq[1]: read /tmp/hosts/odhcpd - 20 names
Fri Oct 20 18:00:19 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
tcp        0      0 10.14.0.1:53            0.0.0.0:*               LISTEN      14338/dnsmasq
tcp        0      0 69.253.xxx.xxx:53       0.0.0.0:*               LISTEN      14338/dnsmasq
tcp        0      0 127.0.0.1:53            0.0.0.0:*               LISTEN      14338/dnsmasq
tcp        0      0 192.168.5.1:53          0.0.0.0:*               LISTEN      14338/dnsmasq
tcp        0      0 2001:558:6027:86:c11b:d34c:xxx:xxx:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fd9f:5b3c:8f49::1:53    :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fe80::ea9f:80ff:feed:599b:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 2601:41:xxx:xxx::1:53  :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fe80::ea9f:80ff:feed:599c:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fe80::ea9f:80ff:feed:599c:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fe80::ea9f:80ff:feed:599e:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 fe80::ea9f:80ff:feed:599d:53 :::*                    LISTEN      14338/dnsmasq
tcp        0      0 ::1:53                  :::*                    LISTEN      14338/dnsmasq
udp        0      0 127.0.0.1:53            0.0.0.0:*                           14338/dnsmasq
udp        0      0 69.253.xxx.xxx:53       0.0.0.0:*                           14338/dnsmasq
udp        0      0 192.168.5.1:53          0.0.0.0:*                           14338/dnsmasq
udp        0      0 10.14.0.1:53            0.0.0.0:*                           14338/dnsmasq
udp        0      0 0.0.0.0:67              0.0.0.0:*                           14338/dnsmasq
udp        0      0 ::1:53                  :::*                                14338/dnsmasq
udp        0      0 fe80::ea9f:80ff:feed:599c:53 :::*                                14338/dnsmasq
udp        0      0 2001:558:6027:86:c11b:d34c:xxx:xxx:53 :::*                                14338/dnsmasq
udp        0      0 fe80::ea9f:80ff:feed:599b:53 :::*                                14338/dnsmasq
udp        0      0 2601:41:xxx:xxx::1:53  :::*                                14338/dnsmasq
udp        0      0 fd9f:5b3c:8f49::1:53    :::*                                14338/dnsmasq
udp        0      0 fe80::ea9f:80ff:feed:599c:53 :::*                                14338/dnsmasq
udp        0      0 fe80::ea9f:80ff:feed:599e:53 :::*                                14338/dnsmasq
udp        0      0 fe80::ea9f:80ff:feed:599d:53 :::*                                14338/dnsmasq

logread -e https-dns; netstat -l -n -p | grep -e https-dns

Fri Oct 20 18:00:19 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 146 crashes, 81 seconds since last crash
Fri Oct 20 18:00:20 2023 user.notice https-dns-proxy: Starting service instances ✓
Fri Oct 20 18:00:41 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 147 crashes, 22 seconds since last crash
Fri Oct 20 18:00:41 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Fri Oct 20 18:00:48 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 148 crashes, 7 seconds since last crash
Fri Oct 20 18:00:48 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Fri Oct 20 18:02:16 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 149 crashes, 88 seconds since last crash
Fri Oct 20 18:02:16 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Fri Oct 20 18:02:16 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 150 crashes, 0 seconds since last crash
Fri Oct 20 18:02:17 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
udp        0      0 127.0.0.1:5053          0.0.0.0:*                           15181/https-dns-pro

pgrep -f -a dnsmasq; pgrep -f -a https-dns

14334 /sbin/ujail -t 5 -n dnsmasq -u -l -r /bin/ubus -r /etc/TZ -r /etc/dnsmasq.conf -r /etc/ethers -r /etc/group -r /etc/hosts -r /etc/passwd -w /tmp/dhcp.leases -r /tmp/dnsmasq.d -r /tmp/hosts -r /usr/bin/jshn -r /usr/lib/dnsmasq/dhcp-script.sh -r /usr/share/dnsmasq/dhcpbogushostname.conf -r /usr/share/dnsmasq/rfc6761.conf -r /usr/share/dnsmasq/trust-anchors.conf -r /usr/share/libubox/jshn.sh -r /var/etc/dnsmasq.conf.cfg01411c -w /var/run/dnsmasq/ -- /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
14338 /usr/sbin/dnsmasq -C /var/etc/dnsmasq.conf.cfg01411c -k -x /var/run/dnsmasq/dnsmasq.cfg01411c.pid
15181 /usr/sbin/https-dns-proxy -r https://cloudflare-dns.com/dns-query -a 127.0.0.1 -p 5053 -b 1.1.1.1,1.0.0.1 -4 -u nobody -g nogroup

head -v -n -0 /etc/resolv. /tmp/resolv. /tmp/resolv./


==> /etc/resolv.conf <==
search lan
nameserver 127.0.0.1
nameserver ::1

==> /tmp/resolv.conf <== search lan nameserver 127.0.0.1 nameserver ::1

==> /tmp/resolv.conf.d <== head: /tmp/resolv.conf.d: I/O error

==> /tmp/resolv.conf.d/resolv.conf.auto <==

Interface wan

nameserver 75.75.75.75 nameserver 75.75.76.76 search hsd1.pa.comcast.net.

Interface wan6

nameserver 2001:558:feed::1 nameserver 2001:558:feed::2


> uci show dhcp; uci show https-dns-proxy

dhcp.@dnsmasq[0]=dnsmasq dhcp.@dnsmasq[0].domainneeded='1' dhcp.@dnsmasq[0].localise_queries='1' dhcp.@dnsmasq[0].rebind_protection='1' dhcp.@dnsmasq[0].local='/lan/' dhcp.@dnsmasq[0].domain='lan' dhcp.@dnsmasq[0].expandhosts='1' dhcp.@dnsmasq[0].authoritative='1' dhcp.@dnsmasq[0].readethers='1' dhcp.@dnsmasq[0].leasefile='/tmp/dhcp.leases' dhcp.@dnsmasq[0].localservice='1' dhcp.@dnsmasq[0].ednspacket_max='1232' dhcp.@dnsmasq[0].quietdhcp='1' dhcp.@dnsmasq[0].filterwin2k='1' dhcp.@dnsmasq[0].doh_backup_noresolv='-1' dhcp.@dnsmasq[0].noresolv='1' dhcp.@dnsmasq[0].doh_backup_server='::1#5054' '127.0.0.1#5054' dhcp.@dnsmasq[0].doh_server='::1#5054' '127.0.0.1#5054' '::1#5053' '127.0.0.1#5053' dhcp.@dnsmasq[0].server='127.0.0.1#5053' dhcp.lan=dhcp dhcp.lan.interface='lan' dhcp.lan.start='100' dhcp.lan.limit='150' dhcp.lan.leasetime='12h' dhcp.lan.dhcpv4='server' dhcp.lan.dhcpv6='server' dhcp.lan.ra='server' dhcp.lan.ra_flags='managed-config' 'other-config' dhcp.wan=dhcp dhcp.wan.interface='wan' dhcp.wan.ignore='1' dhcp.odhcpd=odhcpd dhcp.odhcpd.maindhcp='0' dhcp.odhcpd.leasefile='/tmp/hosts/odhcpd' dhcp.odhcpd.leasetrigger='/usr/sbin/odhcpd-update' dhcp.odhcpd.loglevel='4' https-dns-proxy.config=main https-dns-proxy.config.dnsmasq_config_update='-' https-dns-proxy.config.force_dns='0' https-dns-proxy.config.force_dns_port='53' '853' https-dns-proxy.config.procd_trigger_wan6='0' https-dns-proxy.@https-dns-proxy[0]=https-dns-proxy https-dns-proxy.@https-dns-proxy[0].bootstrap_dns='1.1.1.1,1.0.0.1' https-dns-proxy.@https-dns-proxy[0].resolver_url='https://cloudflare-dns.com/dns-query'


And here are a few examples of debug logs before and after crashes, which to me demonstrates that the crashing occurs independently from anything else output in the debug logs:

Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.517492 main.c:84 Received response for id: C838, len: 94 Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536643 https_client.c:205 150C: < HTTP/2 200 Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536660 https_client.c:205 150C: < server: cloudflare Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536672 https_client.c:205 150C: < date: Fri, 20 Oct 2023 22:19:09 GMT Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536681 https_client.c:205 150C: < content-type: application/dns-message Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536688 https_client.c:205 150C: < access-control-allow-origin: * Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536697 https_client.c:205 150C: < content-length: 144 Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536704 https_client.c:205 150C: < cf-ray: 8194a40879521768-EWR Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536758 https_client.c:587 Released used io event: 0x7fc9019018 Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536781 https_client.c:344 150C: curl request succeeded Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536832 https_client.c:435 150C: CURLINFO_NUM_CONNECTS: 0 Fri Oct 20 18:19:09 2023 daemon.info https-dns-proxy[22191]: [D] 1697840349.536839 https_client.c:447 150C: CURLINFO_EFFECTIVE_URL: https://cloudflare-dns.com/dns-query Fri Oct 20 18:19:12 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 163 crashes, 35 seconds since last crash Fri Oct 20 18:19:12 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓ Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.847714 main.c:219 Version: 2023-05-25-1 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.847729 main.c:220 Built: Oct 15 2023 17:51:39 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.847733 main.c:221 System c-ares: 1.19.1 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.847781 main.c:222 System libcurl: libcurl/8.4.0 mbedTLS/2.28.5 nghttp2/1.57.0 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [W] 1697840352.847803 main.c:236 HTTP/3 is not supported by current libcurl Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.848345 dns_server.c:50 Listening on 127.0.0.1:5053 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [D] 1697840352.848411 logging.c:40 starting periodic log flush timer Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [D] 1697840352.848688 dns_poller.c:178 Nameservers count: 2 Fri Oct 20 18:19:12 2023 daemon.info https-dns-proxy[22595]: [I] 1697840352.848699 main.c:309 DNS polling initialized for 'cloudflare-dns.com'

Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.517973 https_client.c:205 270F: < Connection: keep-alive Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.518004 https_client.c:205 270F: < Access-Control-Allow-Origin: * Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.518016 https_client.c:205 270F: < Content-Length: 100 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.518025 https_client.c:205 270F: < CF-RAY: 8194ed6bfdb9424d-EWR Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519366 https_client.c:112 curl closed socket: 12 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519420 https_client.c:587 Released used io event: 0x7fe7e334a8 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519454 https_client.c:344 270F: curl request succeeded Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519467 https_client.c:435 270F: CURLINFO_NUM_CONNECTS: 0 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519474 https_client.c:447 270F: CURLINFO_EFFECTIVE_URL: https://cloudflare-dns.com/dns-query Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519481 https_client.c:453 270F: CURLINFO_HTTP_VERSION: 1.1 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519489 https_client.c:482 270F: Times: 0.000234, 0.000000, 0.000000, 0.001235, 0.018431, 0.018599 Fri Oct 20 19:09:18 2023 daemon.info https-dns-proxy[5703]: [D] 1697843355.519528 main.c:84 Received response for id: 270F, len: 100 Fri Oct 20 19:09:20 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 221 crashes, 63 seconds since last crash Fri Oct 20 19:09:20 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓ Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.832441 main.c:219 Version: 2023-05-25-1 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.832456 main.c:220 Built: Oct 15 2023 17:51:39 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.832461 main.c:221 System c-ares: 1.19.1 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.832669 main.c:222 System libcurl: libcurl/8.4.0 mbedTLS/2.28.5 nghttp2/1.57.0 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [W] 1697843360.832701 main.c:236 HTTP/3 is not supported by current libcurl Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.833237 dns_server.c:50 Listening on 127.0.0.1:5053 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [D] 1697843360.833305 logging.c:40 starting periodic log flush timer Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [D] 1697843360.833587 dns_poller.c:178 Nameservers count: 2 Fri Oct 20 19:09:20 2023 daemon.info https-dns-proxy[5993]: [I] 1697843360.833598 main.c:309 DNS polling initialized for 'cloudflare-dns.com'

Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9050]: [D] 1697843877.837881 https_client.c:435 E221: CURLINFO_NUM_CONNECTS: 0 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9050]: [D] 1697843877.837911 https_client.c:447 E221: CURLINFO_EFFECTIVE_URL: https://cloudflare-dns.com/dns-query Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9050]: [D] 1697843877.837923 https_client.c:453 E221: CURLINFO_HTTP_VERSION: 2 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9050]: [D] 1697843877.837988 https_client.c:482 E221: Times: 0.000000, 0.000000, 0.000000, 0.000646, 0.045725, 0.045957 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9050]: [D] 1697843877.838033 main.c:84 Received response for id: E221, len: 174 Fri Oct 20 19:17:58 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 232 crashes, 11 seconds since last crash Fri Oct 20 19:17:58 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓ Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.792655 main.c:219 Version: 2023-05-25-1 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.792669 main.c:220 Built: Oct 15 2023 17:51:39 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.792674 main.c:221 System c-ares: 1.19.1 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.792748 main.c:222 System libcurl: libcurl/8.4.0 mbedTLS/2.28.5 nghttp2/1.57.0 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [W] 1697843878.792771 main.c:236 HTTP/3 is not supported by current libcurl Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.792976 dns_server.c:50 Listening on 127.0.0.1:5053 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [D] 1697843878.793039 logging.c:40 starting periodic log flush timer Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [D] 1697843878.793537 dns_poller.c:178 Nameservers count: 2 Fri Oct 20 19:17:58 2023 daemon.info https-dns-proxy[9221]: [I] 1697843878.793553 main.c:309 DNS polling initialized for 'cloudflare-dns.com'

Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.995282 main.c:219 Version: 2023-05-25-1 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.995296 main.c:220 Built: Oct 15 2023 17:51:39 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.995302 main.c:221 System c-ares: 1.19.1 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.995353 main.c:222 System libcurl: libcurl/8.4.0 mbedTLS/2.28.5 nghttp2/1.57.0 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [W] 1697844057.995377 main.c:236 HTTP/3 is not supported by current libcurl Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.997542 dns_server.c:50 Listening on 127.0.0.1:5053 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [D] 1697844057.997656 logging.c:40 starting periodic log flush timer Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [D] 1697844057.998122 dns_poller.c:178 Nameservers count: 2 Fri Oct 20 19:20:57 2023 daemon.info https-dns-proxy[10734]: [I] 1697844057.998141 main.c:309 DNS polling initialized for 'cloudflare-dns.com' Fri Oct 20 19:21:04 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 242 crashes, 6 seconds since last crash Fri Oct 20 19:21:04 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓ Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.711545 main.c:219 Version: 2023-05-25-1 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.711560 main.c:220 Built: Oct 15 2023 17:51:39 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.711564 main.c:221 System c-ares: 1.19.1 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.711952 main.c:222 System libcurl: libcurl/8.4.0 mbedTLS/2.28.5 nghttp2/1.57.0 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [W] 1697844064.711984 main.c:236 HTTP/3 is not supported by current libcurl Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.713624 dns_server.c:50 Listening on 127.0.0.1:5053 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [D] 1697844064.713695 logging.c:40 starting periodic log flush timer Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [D] 1697844064.714346 dns_poller.c:178 Nameservers count: 2 Fri Oct 20 19:21:04 2023 daemon.info https-dns-proxy[10896]: [I] 1697844064.714367 main.c:309 DNS polling initialized for 'cloudflare-dns.com'



I'm happy to try any other troubleshooting/debugging steps that anyone proposes!
AcidSlide commented 1 year ago

I'm also experiencing this on one of my test network. But it seems its on my test network it happens when ifup/ifdown is triggered due to IPv6 changes especially if there happens to be routing issues in IPv6.

Ryan-Goldstein commented 1 year ago

I'm also experiencing this on one of my test network. But it seems its on my test network it happens when ifup/ifdown is triggered due to IPv6 changes especially if there happens to be routing issues in IPv6.

I believe my IPv6 connection is quite stable, and procd_trigger_wan6 is set to the 0 default. Short of disabling IPv6 entirely, any thoughts on what to try to determine whether IPv6 interface changes may be causing these crashes?

stangri commented 1 year ago

@Ryan-Goldstein Can you try taking wan6 down either with ifdown wan6 or thru WebUI?

I've rewritten PROCD triggers sections recently, wonder if this is an unintended consequence.

Ryan-Goldstein commented 1 year ago

@Ryan-Goldstein Can you try taking wan6 down either with ifdown wan6 or thru WebUI?

I've rewritten PROCD triggers sections recently, wonder if this is an unintended consequence.

Good thought - I did ifdown wan6, and it has been well over an hour with no crashes, so it does appear to be caused by IPv6.

Ryan-Goldstein commented 1 year ago

And strangely, after doing ifup wan6, I started seeing a number of 'Starting service instances' messages without any crash messages, then I saw a crash message, as follows:

Sat Oct 21 18:45:32 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Sat Oct 21 18:45:36 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Sat Oct 21 18:45:45 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Sat Oct 21 18:45:52 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Sat Oct 21 18:48:03 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓
Sat Oct 21 18:48:06 2023 daemon.info procd: Instance https-dns-proxy::instance1 s in a crash loop 6 crashes, 3 seconds since last crash
Sat Oct 21 18:48:07 2023 user.notice https-dns-proxy: Starting service instances on_interface_up ✓

Unfortunately, I didn't have debug level logging on at the time, but hopefully that's enough to isolate and resolve the issue in a future build! Let me know if there's anything else you'd like me to try.

stangri commented 1 year ago

@Ryan-Goldstein can you test the init script from this commit? I'd recommend you reboot the router after updating the init script.

Ryan-Goldstein commented 1 year ago

@Ryan-Goldstein can you test the init script from this commit? I'd recommend you reboot the router after updating the init script.

I've never done that kind of thing before, so I'm not quite sure what I'd need to do. Would you mind writing up some quick steps? Command line or luci would be fine.

stangri commented 1 year ago

@Ryan-Goldstein can you test the init script from this commit? I'd recommend you reboot the router after updating the init script.

I've never done that kind of thing before, so I'm not quite sure what I'd need to do. Would you mind writing up some quick steps? Command line or luci would be fine.

You'd need to replace the /etc/init.d/https-dns-proxy file on your router with this file.

AcidSlide commented 1 year ago

You'd need to replace the /etc/init.d/https-dns-proxy file on your router with this file.

Hi @stangri since I've experienced this too and one of my test networks, I'll try to simulate the wan6 related issue.

Ryan-Goldstein commented 1 year ago

@Ryan-Goldstein can you test the init script from this commit? I'd recommend you reboot the router after updating the init script.

I've never done that kind of thing before, so I'm not quite sure what I'd need to do. Would you mind writing up some quick steps? Command line or luci would be fine.

You'd need to replace the /etc/init.d/https-dns-proxy file on your router with this file.

I just loaded that new init file, rebooted my router, and started https-dns-proxy and have been using it for the past several hours with no crashes - so that appears to have resolved the issue!

stangri commented 1 year ago

Should be fixed in https://github.com/openwrt/packages/pull/22489 https://github.com/openwrt/packages/pull/22490 https://github.com/openwrt/packages/pull/22491