search

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.49k forks source link

DNSProxy 0.73.2 service fails to start under openwrt #25010

Closed cyformatician closed 1 month ago

cyformatician commented 1 month ago

Maintainer: @1715173329 Environment: platform independent

Description:

Updating to 0.73.2 causes dnsproxy to fail to start as some changes (regression) to the way configurations are handled were made at the source - https://github.com/AdguardTeam/dnsproxy/commit/011f37a4992822fe2e5ac8f11b3d585321696f2c in response to https://github.com/AdguardTeam/dnsproxy/issues/182

Sun Sep 22 16:16:08 2024 daemon.info dnsproxy[6742]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:08 2024 daemon.info dnsproxy[6742]: 2024/09/22 12:16:08.456560 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:08 2024 daemon.info dnsproxy[6742]: 2024/09/22 12:16:08.456775 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:08 2024 daemon.info dnsproxy[6742]: jail: jail (6767) exited with exit: 1
Sun Sep 22 16:16:13 2024 daemon.info dnsproxy[6786]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:13 2024 daemon.info dnsproxy[6786]: 2024/09/22 12:16:13.516221 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:13 2024 daemon.info dnsproxy[6786]: 2024/09/22 12:16:13.516571 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:13 2024 daemon.info dnsproxy[6786]: jail: jail (6787) exited with exit: 1
Sun Sep 22 16:16:18 2024 daemon.info dnsproxy[6805]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:18 2024 daemon.info dnsproxy[6805]: 2024/09/22 12:16:18.606454 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:18 2024 daemon.info dnsproxy[6805]: 2024/09/22 12:16:18.606707 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:18 2024 daemon.info dnsproxy[6805]: jail: jail (6806) exited with exit: 1
Sun Sep 22 16:16:23 2024 daemon.info dnsproxy[6816]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:23 2024 daemon.info dnsproxy[6816]: 2024/09/22 12:16:23.656157 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:23 2024 daemon.info dnsproxy[6816]: 2024/09/22 12:16:23.656375 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:23 2024 daemon.info dnsproxy[6816]: jail: jail (6817) exited with exit: 1
Sun Sep 22 16:16:28 2024 daemon.info dnsproxy[6835]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:28 2024 daemon.info dnsproxy[6835]: 2024/09/22 12:16:28.716271 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:28 2024 daemon.info dnsproxy[6835]: 2024/09/22 12:16:28.716470 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:28 2024 daemon.info dnsproxy[6835]: jail: jail (6836) exited with exit: 1
Sun Sep 22 16:16:33 2024 daemon.info dnsproxy[6847]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:16:33 2024 daemon.info dnsproxy[6847]: 2024/09/22 12:16:33.776191 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 16:16:33 2024 daemon.info dnsproxy[6847]: 2024/09/22 12:16:33.776412 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 16:16:33 2024 daemon.info dnsproxy[6847]: jail: jail (6848) exited with exit: 1
Sun Sep 22 16:16:33 2024 daemon.info procd: Instance dnsproxy::dnsproxy s in a crash loop 6 crashes, 0 seconds since last crash

Only way to get dnsproxy running again using current configuration format/handlers is by reverting dnsproxy binary to 0.73.1 ... I've tested with both my current configuration as well as with a standard configuration (pushed by openwrt).

Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.427549 INFO dnsproxy starting version=v0.73.1 revision=559d2ef branch=HEAD commit_time=1724168554
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.427972 INFO upstream mode is set prefix=dnsproxy mode=load_balance
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.427998 INFO cache disabled prefix=dnsproxy
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428011 INFO starting dns proxy server prefix=dnsproxy
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428060 INFO creating udp server socket prefix=dnsproxy addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428274 INFO listening to udp prefix=dnsproxy addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428300 INFO creating udp server socket prefix=dnsproxy addr=[::1]:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428393 INFO listening to udp prefix=dnsproxy addr=[::1]:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428427 INFO creating tcp server socket prefix=dnsproxy addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428553 INFO listening to tcp prefix=dnsproxy addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428572 INFO creating tcp server socket prefix=dnsproxy addr=[::1]:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428642 INFO listening to tcp prefix=dnsproxy addr=[::1]:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428881 INFO entering udp listener loop prefix=dnsproxy addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.428903 INFO entering udp listener loop prefix=dnsproxy addr=[::1]:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.429251 INFO entering listener loop prefix=dnsproxy proto=tcp addr=127.0.0.1:5353
Sun Sep 22 16:34:11 2024 daemon.info dnsproxy[11472]: 2024/09/22 12:34:11.429368 INFO entering listener loop prefix=dnsproxy proto=tcp addr=[::1]:5353

Config used:

config dnsproxy 'global'
    option enabled '1'
    list listen_addr '127.0.0.1'
    list listen_addr '::1'
    list listen_port '5353'
    option log_file ''
    option http3 '0'
    option insecure '0'
    option timeout ''
    option ipv6_disabled '0'
    option max_go_routines ''
    option rate_limit ''
    option refuse_any '0'
    option udp_buf_size ''
    option verbose '0'
    option upstream_mode 'load_balance'

config dnsproxy 'bogus_nxdomain'
    list ip_addr ''

config dnsproxy 'cache'
    option enabled '0'
    option cache_optimistic '0'
    option size '65535'
    option min_ttl ''
    option max_ttl ''

config dnsproxy 'dns64'
    option enabled '0'
    option dns64_prefix '64:ff9b::/96'

config dnsproxy 'edns'
    option enabled '0'
    option edns_addr ''

config dnsproxy 'hosts'
    option enabled '0'
    list hosts_files ''

config dnsproxy 'private_rdns'
    option enabled '0'
    list upstream '127.0.0.1'

config dnsproxy 'servers'
    list bootstrap '1.1.1.3:53'
    #list fallback 'REDACTED'
    list upstream 'REDACTED'
    list upstream 'REDACTED'
1715173329 commented 1 month ago

Try command: uci set dnsproxy.hosts.enabled=false uci commit dnsproxy

Then restart the service.

cyformatician commented 1 month ago

No change

Sun Sep 22 18:36:08 2024 daemon.info dnsproxy[27626]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 18:36:08 2024 daemon.info dnsproxy[27626]: 2024/09/22 14:36:08.556353 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 18:36:08 2024 daemon.info dnsproxy[27626]: 2024/09/22 14:36:08.556592 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 18:36:08 2024 daemon.info dnsproxy[27626]: jail: jail (27651) exited with exit: 1
Sun Sep 22 18:36:13 2024 daemon.info dnsproxy[27672]: jail: exec-ing /usr/bin/dnsproxy
Sun Sep 22 18:36:13 2024 daemon.info dnsproxy[27672]: 2024/09/22 14:36:13.606184 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Sun Sep 22 18:36:13 2024 daemon.info dnsproxy[27672]: 2024/09/22 14:36:13.606389 ERROR running dnsproxy err="configuring proxy: creating default handler: open etc/hosts: no such file or directory"
Sun Sep 22 18:36:13 2024 daemon.info dnsproxy[27672]: jail: jail (27673) exited with exit: 1

Config:

config dnsproxy 'global'
    option enabled '1'
    list listen_addr '127.0.0.1'
    list listen_addr '::1'
    list listen_port '5353'
    option http3 '0'
    option insecure '0'
    option ipv6_disabled '0'
    option refuse_any '0'
    option verbose '0'
    option upstream_mode 'load_balance'

config dnsproxy 'bogus_nxdomain'
    list ip_addr ''

config dnsproxy 'cache'
    option enabled '0'
    option cache_optimistic '0'
    option size '65535'

config dnsproxy 'dns64'
    option enabled '0'
    option dns64_prefix '64:ff9b::/96'

config dnsproxy 'edns'
    option enabled '0'

config dnsproxy 'hosts'
    option enabled 'false'
    list hosts_files ''

config dnsproxy 'private_rdns'
    option enabled '0'
    list upstream '127.0.0.1'

config dnsproxy 'servers'
    list bootstrap '1.1.1.3:53'
    list upstream 'REDACTED'
    list upstream 'REDACTED'
1715173329 commented 1 month ago

Seems the cmdline option is broken this time. Will check it tomorrow.

1715173329 commented 1 month ago

This is stupid tbh, related options must be set with an specific order, and --hosts-file-enabled seems broken in this version.

1715173329 commented 1 month ago

25012 should fix current issue.

cyformatician commented 1 month ago

Your fix works as expected - thank you! I see you've also added the mount option due to hosts files being in ujail, explains why hosts_files=etc/hosts wasn't being recognized previously.

Cheers!

Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.167167 INFO dnsproxy starting version=v0.73.2 revision=011f37a branch=HEAD commit_time=1726113961
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.167832 INFO upstream mode is set prefix=dnsproxy mode=load_balance
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.167863 INFO cache disabled prefix=dnsproxy
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.167878 INFO starting dns proxy server prefix=dnsproxy
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.167921 INFO creating udp server socket prefix=dnsproxy addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168117 INFO listening to udp prefix=dnsproxy addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168141 INFO creating udp server socket prefix=dnsproxy addr=[::1]:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168228 INFO listening to udp prefix=dnsproxy addr=[::1]:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168262 INFO creating tcp server socket prefix=dnsproxy addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168399 INFO listening to tcp prefix=dnsproxy addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168421 INFO creating tcp server socket prefix=dnsproxy addr=[::1]:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168520 INFO listening to tcp prefix=dnsproxy addr=[::1]:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168801 INFO entering udp listener loop prefix=dnsproxy addr=[::1]:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168933 INFO entering listener loop prefix=dnsproxy proto=tcp addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168803 INFO entering udp listener loop prefix=dnsproxy addr=127.0.0.1:5353
Mon Sep 23 14:07:22 2024 daemon.info dnsproxy[13208]: 2024/09/23 10:07:22.168964 INFO entering listener loop prefix=dnsproxy proto=tcp addr=[::1]:5353
1715173329 commented 1 month ago

Sorry for the inconvenience and thank you for the test!