[adblock] dns backend restart with adblock blocklist failed

czezz · May 8, 2023, 7:55pm

Hi everyone,
DISTRIB_DESCRIPTION='OpenWrt 22.03.3 r20028-43d71ad93e'
DISTRIB_TARGET='ramips/mt7621'

I cannot start adblock on my OpenWRT box.
Each attempt ends up with: "dns backend restart with adblock blocklist failed".

Note: my OpenWRT is behind another box (ISP router with NAT. ISP does not allow to set their box into a bridge mode).
As a result my OpenWRT box on WAN int has address: 172.16.0.50
And DNS:

root@OpenWrt:~# cat /tmp/resolv.conf.d/resolv.conf.auto 
# Interface wan
nameserver 172.16.0.1
search home

root@OpenWrt:~# logread -e "adblock"
Mon May  8 19:26:16 2023 user.info adblock-4.1.5[3702]: backup directory '/tmp/adblock-Backup' created
Mon May  8 19:26:16 2023 user.info adblock-4.1.5[3702]: adblock instance started ::: action: start, priority: 0, pid: 3702
Mon May  8 19:29:11 2023 user.err adblock-4.1.5[3702]: dns backend restart with adblock blocklist failed

root@OpenWrt:~# /etc/init.d/adblock status
::: adblock runtime information
  + adblock_status  : error
  + adblock_version : 4.1.5
  + blocked_domains : 0
  + active_sources  : adaway, adguard, disconnect, yoyo
  + dns_backend     : dnsmasq (-), /tmp/dnsmasq.d
  + run_utils       : download: /bin/uclient-fetch, sort: /usr/libexec/sort-coreutils, awk: /bin/busybox
  + run_ifaces      : trigger: -, report: -
  + run_directories : base: /tmp, backup: /tmp/adblock-Backup, report: /tmp/adblock-Report, jail: /tmp
  + run_flags       : backup: ✔, flush: ✘, force: ✘, search: ✘, report: ✘, mail: ✘, jail: ✘
  + last_run        : start, 4m 6s, 120/78/61, 2023-05-08T19:30:22+00:00
  + system          : Netgear R6220, OpenWrt 22.03.3 r20028-43d71ad93e

efahl · May 9, 2023, 1:56am

Do a logread -e dnsmasq and report the output. That should show us some error messages from the backend that's failing.

frollic · May 9, 2023, 4:01am

You haven't by any chance implemented dns hijacking firewall rules, or set the router to use itself as dns ?

czezz · May 9, 2023, 6:51am

Hi guys,
Thank you for replies

@efahl - from the logread i see "daemon.info dnsmasq[1]: exiting on receipt of SIGTERM" but no real reason for that
@frollic - not that I know. It is a default firewall configuration. What should I look for to find out if the rule(s) is there?

Full log ( logread -e dnsmasq) from this event/time range:

Mon May  8 19:20:54 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Mon May  8 19:26:16 2023 daemon.info dnsmasq[1]: exiting on receipt of SIGTERM
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: started, version 2.86 cachesize 150
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: DNS service limited to local subnets
Mon May  8 19:26:20 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-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: UBus support enabled: connected to system bus
Mon May  8 19:26:20 2023 daemon.info dnsmasq-dhcp[1]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using nameserver 172.16.0.1#53
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: using only locally-known addresses for lan
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: read /etc/hosts - 4 addresses
Mon May  8 19:26:20 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon May  8 19:26:20 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Mon May  8 19:27:58 2023 daemon.info dnsmasq[1]: exiting on receipt of SIGTERM
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: started, version 2.86 cachesize 150
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: DNS service limited to local subnets
Mon May  8 19:28:03 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-auth no-cryptohash no-DNSSEC no-ID loop-detect inotify dumpfile
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: UBus support enabled: connected to system bus
Mon May  8 19:28:03 2023 daemon.info dnsmasq-dhcp[1]: DHCP, IP range 192.168.1.100 -- 192.168.1.249, lease time 12h
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for sym.zone
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using only locally-known addresses for piwik.qmmedia.zone
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using standard nameservers for example.com
Mon May  8 19:28:03 2023 daemon.info dnsmasq[1]: using 55287 more local addresses
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using nameserver 172.16.0.1#53
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for test
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for onion
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for localhost
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for local
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for invalid
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for bind
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for sym.zone
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using only locally-known addresses for piwik.qmmedia.zone
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using standard nameservers for example.com
Mon May  8 19:28:04 2023 daemon.info dnsmasq[1]: using 55287 more local addresses
Mon May  8 19:28:06 2023 daemon.info dnsmasq[1]: read /etc/hosts - 4 addresses
Mon May  8 19:28:06 2023 daemon.info dnsmasq[1]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon May  8 19:28:06 2023 daemon.info dnsmasq-dhcp[1]: read /etc/ethers - 0 addresses
Mon May  8 19:29:11 2023 daemon.info dnsmasq[1]: exiting on receipt of SIGTERM
Mon May  8 19:29:15 2023 daemon.info dnsmasq[1]: started, version 2.86 cachesize 150

frollic · May 9, 2023, 6:54am

which device is this ?

czezz · May 9, 2023, 7:12am

Netgear R6220

frollic · May 9, 2023, 7:14am

doesn't tell us anything, there a sh-t load of devices using the same SoC - https://downloads.openwrt.org/releases/22.03.5/targets/ramips/mt7621/

czezz · May 9, 2023, 9:01am

It is: Netgear R6220

waynea · May 9, 2023, 9:41am

Just as a matter of interest? Why not simplify your architecture by replacing the ISP router with a simple modem and let your openWRT router handle everything?

czezz · May 9, 2023, 11:31am

I wouldnt know where to get "simple modem" and if it would work or not.
Does anyone else have the same problem with adblock?

waynea · May 9, 2023, 11:47am

Something like this...a draytek vigor 120 which is dirt cheap on ebay. Plug the telephone cable in, and the Ethernet cable into your routers WAN port.

You then - with your ISP username and password, configure a pppoe connection in LuCi. So you get rid of double natting and remove a suboptimal (as that is what ISP routers always are) from your network.

I appreciate this doesn't answer your original question though

frollic · May 9, 2023, 11:48am

never seen a post, but I haven't been here that long.

I assume everything works if you disable the adblock ?

czezz · May 9, 2023, 11:52am

Yes, correct. Everything else works just fine.
Im tempted to reinstall my OpenWRT from scratch and see after if the problem is still there.

frollic · May 9, 2023, 11:54am

and if you enable it, but pick some other ad list ?

dibdot · May 9, 2023, 11:54am

Just enable debug in adblock and restart the service to receive much more information.

czezz · May 9, 2023, 2:53pm

How can I do that?
I dont see any switch to debug log level:

root@OpenWrt:~# /etc/init.d/adblock --help
Syntax: /etc/init.d/adblock [command]

Available commands:
	start           Start the service
	stop            Stop the service
	restart         Restart the service
	reload          Reload configuration files (or restart if service does not implement reload)
	enable          Enable service autostart
	disable         Disable service autostart
	enabled         Check if service is started on boot
	suspend         Suspend adblock processing
	resume          Resume adblock processing
	query           <domain> Query active blocklists and backups for a specific domain
	report          [[<cli>|<mail>|<gen>|<json>] [<top_count>] [<res_count>] [<search>]] Print DNS statistics with an optional search parameter
	list            [<add>|<add_utc>|<add_eng>|<add_stb>|<remove>|<remove_utc>|<remove_eng>|<remove_stb>] <source(s)> List/Edit available sources
	timer           [<add> <tasks> <hour> [<minute>] [<weekday>]]|[<remove> <line no.>] List/Edit cron update intervals
	running         Check if service is running
	status          Service status
	trace           Start with syscall trace
	info            Dump procd service info

efahl · May 9, 2023, 3:39pm

It's in the config:

$ cat /etc/config/adblock

config adblock 'global'
        option adb_enabled '1'
        option adb_debug '0'
...

Or in Additional Settings in the LuCI interface.

czezz · May 9, 2023, 4:05pm

Thanks! Started it with debug log level but i cant really see anything special.
Can anyone here have a look also, please?

Tue May  9 15:45:23 2023 user.debug adblock-4.1.5[13497]: f_dns    ::: dns: dnsmasq, dns_dir: /tmp/dnsmasq.d, dns_file: adb_list.overall, dns_user: dnsmasq, dns_instance: 0, backup: 1, backup_dir: /tmp/adblock-Backup, jail_dir: /tmp
Tue May  9 15:45:23 2023 user.debug adblock-4.1.5[13497]: f_fetch  ::: fetch_util: /bin/uclient-fetch, fetch_parm:  --timeout=20 -O
Tue May  9 15:46:33 2023 user.debug adblock-4.1.5[13497]: f_dnsup  ::: dns: dnsmasq, cache_cmd: -, lookup_cmd: /usr/bin/nslookup, lookup_domain: example.com, restart_rc: 0, dns_flush: 0, dns_timeout: 60, dns_cnt: 61, in_rc: 4, out_rc: 4
Tue May  9 15:46:33 2023 user.debug adblock-4.1.5[13497]: f_rmtemp ::: tmp_dir: -, src_file: /tmp/adb_sources.json, pid_file: /var/run/adblock.pid
Tue May  9 15:46:33 2023 user.debug adblock-4.1.5[13497]: f_rmdns  ::: dns: dnsmasq, status: false, dns_dir: /tmp/dnsmasq.d, dns_file: adb_list.overall, rt_file: /tmp/adb_runtime.json, backup_dir: /tmp/adblock-Backup
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_dns    ::: dns: dnsmasq, dns_dir: /tmp/dnsmasq.d, dns_file: adb_list.overall, dns_user: dnsmasq, dns_instance: 0, backup: 1, backup_dir: /tmp/adblock-Backup, jail_dir: /tmp
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_fetch  ::: fetch_util: /bin/uclient-fetch, fetch_parm:  --timeout=20 -O
Tue May  9 15:53:46 2023 user.info adblock-4.1.5[14886]: adblock instance started ::: action: start, priority: 0, pid: 14886
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_jsnup  ::: status: running, cnt: , mail: 0, mail_service: /etc/adblock/adblock.mail, mail_cnt: 0, mail_pid: -
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_uci    ::: config: dhcp, change:
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_uci    ::: config: firewall, change:
Tue May  9 15:53:46 2023 user.debug adblock-4.1.5[14886]: f_temp   ::: tmp_base: /tmp, tmp_dir: /tmp/tmp.ChnDgn, sort_options: --temporary-directory=/tmp/tmp.ChnDgn --compress-program=gzip --parallel=2, pid_file: /var/run/adblock.pid
Tue May  9 15:54:55 2023 user.debug adblock-4.1.5[14886]: f_dnsup  ::: dns: dnsmasq, cache_cmd: -, lookup_cmd: /usr/bin/nslookup, lookup_domain: example.com, restart_rc: 0, dns_flush: 0, dns_timeout: 60, dns_cnt: 61, in_rc: 0, out_rc: 4
Tue May  9 15:54:55 2023 user.debug adblock-4.1.5[14886]: f_main   ::: memory: 120/77/60, cores: 2, safe_search: 0, force_dns: 0, awk: /usr/bin/awk
Tue May  9 15:54:55 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: iplist, mode: iplist, cnt: 0, in_rc: 0, out_rc: 0
Tue May  9 15:54:56 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: blacklist, mode: blacklist, cnt: 1, in_rc: 0, out_rc: 0
Tue May  9 15:54:56 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: whitelist, mode: whitelist, cnt: 1, in_rc: 0, out_rc: 0
Tue May  9 15:54:56 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adaway, mode: restore, cnt: 0, in_rc: 4, out_rc: 4
Tue May  9 15:54:56 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adguard, mode: restore, cnt: 0, in_rc: 4, out_rc: 4
Tue May  9 15:55:00 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adaway, mode: download, cnt: 6540, in_rc: 0, out_rc: 0
Tue May  9 15:55:01 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adaway, mode: backup, cnt: 6540, in_rc: 0, out_rc: 0
Tue May  9 15:55:14 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adguard, mode: download, cnt: 51283, in_rc: 0, out_rc: 0
Tue May  9 15:55:14 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: adguard, mode: backup, cnt: 51283, in_rc: 0, out_rc: 0
Tue May  9 15:55:14 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: disconnect, mode: restore, cnt: 0, in_rc: 4, out_rc: 4
Tue May  9 15:55:14 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: yoyo, mode: restore, cnt: 0, in_rc: 4, out_rc: 4
Tue May  9 15:55:17 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: yoyo, mode: download, cnt: 3740, in_rc: 0, out_rc: 0
Tue May  9 15:55:17 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: yoyo, mode: backup, cnt: 3740, in_rc: 0, out_rc: 0
Tue May  9 15:55:18 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: disconnect, mode: download, cnt: 2735, in_rc: 0, out_rc: 0
Tue May  9 15:55:18 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: disconnect, mode: backup, cnt: 2735, in_rc: 0, out_rc: 0
Tue May  9 15:55:18 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: -, mode: merge, cnt: 59714, in_rc: 4, out_rc: 0
Tue May  9 15:55:26 2023 user.debug adblock-4.1.5[14886]: f_tld    ::: source: /tmp/tmp.ChnDgn/adb_list.overall, cnt: 59714, cnt_tld: 55318
Tue May  9 15:55:30 2023 user.debug adblock-4.1.5[14886]: f_list   ::: name: -, mode: final, cnt: 55318, in_rc: 4, out_rc: 0
Tue May  9 15:56:43 2023 user.debug adblock-4.1.5[14886]: f_dnsup  ::: dns: dnsmasq, cache_cmd: -, lookup_cmd: /usr/bin/nslookup, lookup_domain: example.com, restart_rc: 0, dns_flush: 0, dns_timeout: 60, dns_cnt: 61, in_rc: 0, out_rc: 4
Tue May  9 15:56:43 2023 user.err adblock-4.1.5[14886]: dns backend restart with adblock blocklist failed
Tue May  9 15:57:54 2023 user.debug adblock-4.1.5[14886]: f_dnsup  ::: dns: dnsmasq, cache_cmd: -, lookup_cmd: /usr/bin/nslookup, lookup_domain: example.com, restart_rc: 0, dns_flush: 0, dns_timeout: 60, dns_cnt: 61, in_rc: 4, out_rc: 4
Tue May  9 15:57:54 2023 user.debug adblock-4.1.5[14886]: f_rmtemp ::: tmp_dir: /tmp/tmp.ChnDgn, src_file: /tmp/adb_sources.json, pid_file: /var/run/adblock.pid
Tue May  9 15:57:54 2023 user.debug adblock-4.1.5[14886]: f_rmdns  ::: dns: dnsmasq, status: true, dns_dir: /tmp/dnsmasq.d, dns_file: adb_list.overall, rt_file: /tmp/adb_runtime.json, backup_dir: /tmp/adblock-Backup
Tue May  9 15:57:54 2023 user.debug adblock-4.1.5[14886]: f_jsnup  ::: status: error, cnt: 0, mail: 0, mail_service: /etc/adblock/adblock.mail, mail_cnt: 0, mail_pid:

frollic · May 9, 2023, 4:07pm

Doesn't look too good

czezz · May 9, 2023, 4:10pm

Ya, thats the problem I highlighted in my opening post and in a title