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

DNSProxy 0.73.2 service fails to start under openwrt #25010

Closed
cyformatician opened this issue Sep 22, 2024 · 7 comments · Fixed by #25012
Closed

DNSProxy 0.73.2 service fails to start under openwrt #25010

cyformatician opened this issue Sep 22, 2024 · 7 comments · Fixed by #25012
Labels

Comments

@cyformatician
Copy link

cyformatician commented Sep 22, 2024

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 - AdguardTeam/dnsproxy@011f37a in response to AdguardTeam/dnsproxy#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'
cyformatician referenced this issue Sep 22, 2024
Migrate "all_servers" and "fastest_addr" to new option "upstream_mode".

Fixes: d0823a8 ("dnsproxy: Update to 0.73.2")
Signed-off-by: Tianling Shen <[email protected]>
@cyformatician cyformatician changed the title DNSProxy 0.73.2 binary fails to start under openwrt DNSProxy 0.73.2 service fails to start under openwrt Sep 22, 2024
@1715173329 1715173329 added the bug label Sep 22, 2024
@1715173329
Copy link
Member

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

Then restart the service.

@cyformatician
Copy link
Author

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
Copy link
Member

1715173329 commented Sep 22, 2024

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

@1715173329
Copy link
Member

1715173329 commented Sep 23, 2024

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

@1715173329
Copy link
Member

#25012 should fix current issue.

@cyformatician
Copy link
Author

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
Copy link
Member

Sorry for the inconvenience and thank you for the test!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants