Groups and Regex

sqlite> SELECT COUNT(*) FROM client WHERE ip = '192.168.1.6';
0
sqlite> SELECT GROUP_CONCAT(group_id) FROM client_by_group WHERE client_id = (SELECT id FROM client WHERE ip = '192.168.1.6');

Okay, so all unassociated regex filters should be loaded for this client. As expected.

Next request:

SELECT * from vw_regex_blacklist WHERE group_id IN (0);
sqlite> SELECT * from vw_regex_blacklist WHERE group_id IN (0);
^(.+[_.-])?adse?rv(er?|ice)?s?[0-9]*[_.-]|18|0
^(.+[_.-])?telemetry[_.-]|19|0
^(www[0-9]*\.)?xn--|20|0
^adim(age|g)s?[0-9]*[_.-]|21|0
^adtrack(er|ing)?[0-9]*[_.-]|22|0
^advert(s|is(ing|ements?))?[0-9]*[_.-]|23|0
^aff(iliat(es?|ion))?[_.-]|24|0
^analytics?[_.-]|25|0
^banners?[_.-]|26|0
^beacons?[0-9]*[_.-]|27|0
^count(ers?)?[0-9]*[_.-]|28|0
^mads\.|29|0
^pixels?[-.]|30|0
^stat(s|istics)?[0-9]*[_.-]|31|0
^track(ers?|ing)?[0-9]*[_.-]|32|0
^traff(ic)?[.-]|33|0
^(.+[_.-])?ytimg*|50|0
^(.+[_.-])?ad[sxv]?[0-9]*[_.-]|78|0

Hmm, so everything is as expected. Could you add

DEBUG_DATABASE=true
DEBUG_REGEX=true

to your /etc/pihole/pihole-FTL.conf and run pihole restartdns? (You may already have the latter config line).

Then run tail -f /var/log/pihole-FTL.log in one terminal and pihole restartdns reload-lists in another. What is printed into the file?

Taking some liberties with selective copy/paste because I have a lot of hosts making a lot of noise. Please let me know if I missed something relevant:

[2020-02-05 17:56:53.617 6559] Shutting down...
[2020-02-05 17:56:53.618 6559] dbquery: "BEGIN TRANSACTION"
[2020-02-05 17:56:53.620 6559] dbquery: "END TRANSACTION"
[2020-02-05 17:56:53.643 6559] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 1, 1580925411 );"
[2020-02-05 17:56:53.656 6559] dbquery: "UPDATE counters SET value = value + 93 WHERE id = 0;"
[2020-02-05 17:56:53.667 6559] dbquery: "UPDATE counters SET value = value + 0 WHERE id = 1;"
[2020-02-05 17:56:53.667 6559] Notice: Queries stored in FTL_db: 93 (took 49.5 ms, last SQLite ID 2365339)
[2020-02-05 17:56:53.667 6559] Finished final database update
[2020-02-05 17:56:53.672 6559] ########## FTL terminated after 69378.0 ms! ##########
[2020-02-05 17:56:54.956 6822] Using log file /var/log/pihole-FTL.log
[2020-02-05 17:56:54.956 6822] ########## FTL started! ##########
[2020-02-05 17:56:54.956 6822] FTL branch: release/v5.0
[2020-02-05 17:56:54.956 6822] FTL version: vDev-a90f14b
[2020-02-05 17:56:54.956 6822] FTL commit: a90f14b
[2020-02-05 17:56:54.956 6822] FTL date: 2020-01-29 22:30:55 +0100
[2020-02-05 17:56:54.956 6822] FTL user: pihole
[2020-02-05 17:56:54.956 6822] Compiled for armhf (compiled on CI) using arm-linux-gnueabihf-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-02-05 17:56:54.956 6822] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-02-05 17:56:54.957 6822]    SOCKET_LISTENING: only local
[2020-02-05 17:56:54.957 6822]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-02-05 17:56:54.957 6822]    MAXDBDAYS: max age for stored queries is 365 days
[2020-02-05 17:56:54.957 6822]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-02-05 17:56:54.957 6822]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-02-05 17:56:54.957 6822]    DBINTERVAL: saving to DB file every minute
[2020-02-05 17:56:54.957 6822]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-02-05 17:56:54.957 6822]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-02-05 17:56:54.957 6822]    PRIVACYLEVEL: Set to 0
[2020-02-05 17:56:54.958 6822]    IGNORE_LOCALHOST: Show queries from localhost
[2020-02-05 17:56:54.958 6822]    BLOCKINGMODE: Null IPs for blocked domains
[2020-02-05 17:56:54.958 6822]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-02-05 17:56:54.958 6822]    DBIMPORT: Importing history from database
[2020-02-05 17:56:54.958 6822]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-02-05 17:56:54.958 6822]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-02-05 17:56:54.958 6822]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-02-05 17:56:54.958 6822]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-02-05 17:56:54.958 6822]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-02-05 17:56:54.958 6822]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-02-05 17:56:54.958 6822]    PARSE_ARP_CACHE: Active
[2020-02-05 17:56:54.959 6822]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-02-05 17:56:54.959 6822]    CNAME_DEEP_INSPECT: Active
[2020-02-05 17:56:54.959 6822] *****************************
[2020-02-05 17:56:54.959 6822] * Debugging enabled         *
[2020-02-05 17:56:54.959 6822] * DEBUG_DATABASE        YES *
[2020-02-05 17:56:54.959 6822] * DEBUG_NETWORKING      NO  *
[2020-02-05 17:56:54.959 6822] * DEBUG_LOCKS           NO  *
[2020-02-05 17:56:54.959 6822] * DEBUG_QUERIES         NO  *
[2020-02-05 17:56:54.959 6822] * DEBUG_FLAGS           NO  *
[2020-02-05 17:56:54.959 6822] * DEBUG_SHMEM           NO  *
[2020-02-05 17:56:54.959 6822] * DEBUG_GC              NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_ARP             NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_REGEX           YES *
[2020-02-05 17:56:54.960 6822] * DEBUG_API             NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_OVERTIME        NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_EXTBLOCKED      NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_CAPS            NO  *
[2020-02-05 17:56:54.960 6822] * DEBUG_DNSMASQ_LINES   NO  *
[2020-02-05 17:56:54.960 6822] *****************************
[2020-02-05 17:56:54.960 6822] Finished config file parsing
[2020-02-05 17:56:54.962 6822] Database version is 5
[2020-02-05 17:56:54.962 6822] Database successfully initialized
[2020-02-05 17:56:54.962 6822] DB_read_queries(): "SELECT * FROM queries WHERE timestamp >= 1580839014"
[2020-02-05 17:56:54.963 6822] New forward server: 192.168.1.1 (0/1024)
[2020-02-05 17:56:54.963 6822] New forward server: 2001:4860:4860::8888 (1/1024)
[2020-02-05 17:56:54.965 6822] Resizing "/FTL-clients" from 20480 to 40960
[2020-02-05 17:56:54.965 6822] New forward server: 2001:4860:4860::8844 (2/1024)
[2020-02-05 17:56:54.966 6822] Resizing "/FTL-strings" from 4096 to 8192
[2020-02-05 17:56:54.971 6822] New forward server: 8.8.4.4 (3/1024)
[2020-02-05 17:56:54.978 6822] Resizing "/FTL-queries" from 196608 to 393216
[2020-02-05 17:56:54.991 6822] Resizing "/FTL-strings" from 8192 to 12288
[2020-02-05 17:56:54.997 6822] Resizing "/FTL-queries" from 393216 to 589824
[2020-02-05 17:56:55.001 6822] Resizing "/FTL-strings" from 12288 to 16384
[2020-02-05 17:56:55.013 6822] New forward server: 8.8.8.8 (4/1024)
[2020-02-05 17:56:55.022 6822] Resizing "/FTL-strings" from 16384 to 20480
[2020-02-05 17:56:55.023 6822] Resizing "/FTL-queries" from 589824 to 786432
[2020-02-05 17:56:55.049 6822] Resizing "/FTL-queries" from 786432 to 983040
[2020-02-05 17:56:55.055 6822] Resizing "/FTL-strings" from 20480 to 24576
[2020-02-05 17:56:55.073 6822] Resizing "/FTL-strings" from 24576 to 28672
[2020-02-05 17:56:55.082 6822] Resizing "/FTL-strings" from 28672 to 32768
[2020-02-05 17:56:55.091 6822] Resizing "/FTL-queries" from 983040 to 1179648
[2020-02-05 17:56:55.099 6822] Resizing "/FTL-strings" from 32768 to 36864
[2020-02-05 17:56:55.125 6822] Resizing "/FTL-queries" from 1179648 to 1376256
[2020-02-05 17:56:55.149 6822] Resizing "/FTL-strings" from 36864 to 40960
[2020-02-05 17:56:55.160 6822] Resizing "/FTL-queries" from 1376256 to 1572864
[2020-02-05 17:56:55.189 6822] Resizing "/FTL-strings" from 40960 to 45056
[2020-02-05 17:56:55.196 6822] Resizing "/FTL-queries" from 1572864 to 1769472
[2020-02-05 17:56:55.222 6822] Resizing "/FTL-queries" from 1769472 to 1966080
[2020-02-05 17:56:55.243 6822] Resizing "/FTL-strings" from 45056 to 49152
[2020-02-05 17:56:55.261 6822] Resizing "/FTL-queries" from 1966080 to 2162688
[2020-02-05 17:56:55.276 6822] Resizing "/FTL-strings" from 49152 to 53248
[2020-02-05 17:56:55.300 6822] Resizing "/FTL-queries" from 2162688 to 2359296
[2020-02-05 17:56:55.333 6822] Resizing "/FTL-strings" from 53248 to 57344
[2020-02-05 17:56:55.336 6822] Resizing "/FTL-queries" from 2359296 to 2555904
[2020-02-05 17:56:55.363 6822] Resizing "/FTL-queries" from 2555904 to 2752512
[2020-02-05 17:56:55.386 6822] Resizing "/FTL-queries" from 2752512 to 2949120
[2020-02-05 17:56:55.431 6822] Resizing "/FTL-queries" from 2949120 to 3145728
[2020-02-05 17:56:55.464 6822] Resizing "/FTL-queries" from 3145728 to 3342336
[2020-02-05 17:56:55.502 6822] Resizing "/FTL-queries" from 3342336 to 3538944
[2020-02-05 17:56:55.507 6822] Resizing "/FTL-strings" from 57344 to 61440
[2020-02-05 17:56:55.541 6822] Resizing "/FTL-queries" from 3538944 to 3735552
[2020-02-05 17:56:55.576 6822] Resizing "/FTL-queries" from 3735552 to 3932160
[2020-02-05 17:56:55.594 6822] Resizing "/FTL-queries" from 3932160 to 4128768
[2020-02-05 17:56:55.626 6822] Resizing "/FTL-queries" from 4128768 to 4325376
[2020-02-05 17:56:55.644 6822] Resizing "/FTL-queries" from 4325376 to 4521984
[2020-02-05 17:56:55.661 6822] Imported 93326 queries from the long-term database
[2020-02-05 17:56:55.662 6822]  -> Total DNS queries: 93326
[2020-02-05 17:56:55.662 6822]  -> Cached DNS queries: 29073
[2020-02-05 17:56:55.662 6822]  -> Forwarded DNS queries: 52927
[2020-02-05 17:56:55.662 6822]  -> Exactly blocked DNS queries: 11326
[2020-02-05 17:56:55.662 6822]  -> Unknown DNS queries: 0
[2020-02-05 17:56:55.662 6822]  -> Unique domains: 2485
[2020-02-05 17:56:55.662 6822]  -> Unique clients: 50
[2020-02-05 17:56:55.662 6822]  -> Known forward destinations: 5
[2020-02-05 17:56:55.662 6822] Successfully accessed setupVars.conf
[2020-02-05 17:56:55.667 6824] PID of FTL process: 6824
[2020-02-05 17:56:55.668 6824] Listening on port 4711 for incoming IPv4 telnet connections
[2020-02-05 17:56:55.668 6824] Listening on port 4711 for incoming IPv6 telnet connections
[2020-02-05 17:56:55.668 6824] Listening on Unix socket
[2020-02-05 17:56:55.671 6824] Reloading DNS cache
[2020-02-05 17:56:55.671 6824] Blocking status is enabled
[2020-02-05 17:56:55.671 6824] *****************************
[2020-02-05 17:56:55.671 6824] * Debugging enabled         *
[2020-02-05 17:56:55.672 6824] * DEBUG_DATABASE        YES *
[2020-02-05 17:56:55.672 6824] * DEBUG_NETWORKING      NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_LOCKS           NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_QUERIES         NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_FLAGS           NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_SHMEM           NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_GC              NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_ARP             NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_REGEX           YES *
[2020-02-05 17:56:55.672 6824] * DEBUG_API             NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_OVERTIME        NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_EXTBLOCKED      NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_CAPS            NO  *
[2020-02-05 17:56:55.672 6824] * DEBUG_DNSMASQ_LINES   NO  *
[2020-02-05 17:56:55.672 6824] *****************************
[2020-02-05 17:56:55.674 6824] gravityDB_open(): Successfully opened gravity.db
[2020-02-05 17:56:55.675 6824] Initializing gravity statements for 192.168.1.137
[2020-02-05 17:56:55.675 6824] Querying gravity database for client 192.168.1.137
[2020-02-05 17:56:55.675 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (5));
[2020-02-05 17:56:55.675 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (5));
[2020-02-05 17:56:55.676 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (5));
[2020-02-05 17:56:55.676 6824] Initializing gravity statements for 192.168.1.5
[2020-02-05 17:56:55.676 6824] Querying gravity database for client 192.168.1.5
[2020-02-05 17:56:55.676 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (5));
[2020-02-05 17:56:55.676 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (5));
[2020-02-05 17:56:55.677 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (5));
 [2020-02-05 17:56:55.688 6824] Initializing gravity statements for 192.168.1.6
[2020-02-05 17:56:55.688 6824] Querying gravity database for client 192.168.1.6
[2020-02-05 17:56:55.688 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (0));
[2020-02-05 17:56:55.688 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (0));
[2020-02-05 17:56:55.689 6824] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (0));
 [2020-02-05 17:56:56.565 6824] Compiled 0 whitelist and 18 blacklist regex filters in 42.0 msec
[2020-02-05 17:56:56.566 6824] domain_in_whitelist("printer770.taub.lan"): 0
[2020-02-05 17:56:56.566 6824] domain_in_blacklist("printer770.taub.lan"): 0
[2020-02-05 17:56:56.566 6824] domain_in_gravity("printer770.taub.lan"): 0
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:56.567 6824] Regex blacklist ID 17 not enabled for this client
[2020-02-05 17:56:58.087 6824] domain_in_whitelist("peoplehub.xboxlive.com"): 0
[2020-02-05 17:56:58.087 6824] domain_in_blacklist("peoplehub.xboxlive.com"): 0
[2020-02-05 17:56:58.088 6824] domain_in_gravity("peoplehub.xboxlive.com"): 0
[2020-02-05 17:56:58.088 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:58.088 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:58.088 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:58.088 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:58.088 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:58.089 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:58.089 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:58.089 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:58.089 6824] Regex blacklist ID 17 not enabled for this client
[2020-02-05 17:56:58.108 6824] domain_in_whitelist("peoplehub.xboxlive.com.edgekey.net"): 0
[2020-02-05 17:56:58.108 6824] domain_in_blacklist("peoplehub.xboxlive.com.edgekey.net"): 0
[2020-02-05 17:56:58.108 6824] domain_in_gravity("peoplehub.xboxlive.com.edgekey.net"): 0
[2020-02-05 17:56:58.109 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:58.109 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:58.109 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:58.109 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:58.109 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:58.110 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:58.110 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:58.110 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:58.110 6824] Regex blacklist ID 17 not enabled for this client
[2020-02-05 17:56:58.111 6824] domain_in_whitelist("e87.b.akamaiedge.net"): 0
[2020-02-05 17:56:58.111 6824] domain_in_blacklist("e87.b.akamaiedge.net"): 0
[2020-02-05 17:56:58.112 6824] domain_in_gravity("e87.b.akamaiedge.net"): 0
[2020-02-05 17:56:58.112 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:58.112 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:58.112 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:58.112 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:58.113 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:58.113 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:58.113 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:58.113 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:58.113 6824] Regex blacklist ID 17 not enabled for this client
[2020-02-05 17:56:59.810 6824] domain_in_whitelist("graph.facebook.com"): 0
[2020-02-05 17:56:59.811 6824] domain_in_blacklist("graph.facebook.com"): 0
[2020-02-05 17:56:59.811 6824] domain_in_gravity("graph.facebook.com"): 0
[2020-02-05 17:56:59.811 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:59.811 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:59.812 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:59.813 6824] Regex blacklist ID 17 not enabled for this client
[2020-02-05 17:56:59.833 6824] domain_in_whitelist("api.facebook.com"): 0
[2020-02-05 17:56:59.834 6824] domain_in_blacklist("api.facebook.com"): 0
[2020-02-05 17:56:59.834 6824] domain_in_gravity("api.facebook.com"): 0
[2020-02-05 17:56:59.834 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:56:59.834 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:56:59.835 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:56:59.835 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:56:59.835 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:56:59.835 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:56:59.835 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:56:59.836 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:56:59.836 6824] Regex blacklist ID 17 not enabled for this client
 [2020-02-05 17:57:00.077 6824] dbquery: "BEGIN TRANSACTION"
[2020-02-05 17:57:00.078 6824] dbquery: "END TRANSACTION"
[2020-02-05 17:57:00.094 6824] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 1, 1580925419 );"
[2020-02-05 17:57:00.118 6824] dbquery: "UPDATE counters SET value = value + 4 WHERE id = 0;"
[2020-02-05 17:57:00.130 6824] dbquery: "UPDATE counters SET value = value + 0 WHERE id = 1;"
[2020-02-05 17:57:00.131 6824] Notice: Queries stored in FTL_db: 4 (took 56.2 ms, last SQLite ID 2365343)
[2020-02-05 17:57:00.132 6824] dbquery: "BEGIN TRANSACTION"
[2020-02-05 17:57:00.145 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580925358) WHERE id = 3;"
[2020-02-05 17:57:00.145 6824] dbquery: "UPDATE network SET numQueries = numQueries + 557 WHERE id = 3;"
[2020-02-05 17:57:00.146 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(3,'192.168.1.6');"
[2020-02-05 17:57:00.146 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580925418) WHERE id = 2;"
[2020-02-05 17:57:00.147 6824] dbquery: "UPDATE network SET numQueries = numQueries + 18832 WHERE id = 2;"
[2020-02-05 17:57:00.147 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(2,'192.168.1.5');"
[2020-02-05 17:57:00.147 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580925298) WHERE id = 7;"
[2020-02-05 17:57:00.147 6824] dbquery: "UPDATE network SET numQueries = numQueries + 377 WHERE id = 7;"
[2020-02-05 17:57:00.147 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(7,'192.168.1.110');"
[2020-02-05 17:57:00.148 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580925411) WHERE id = 8;"
[2020-02-05 17:57:00.148 6824] dbquery: "UPDATE network SET numQueries = numQueries + 25640 WHERE id = 8;"
[2020-02-05 17:57:00.148 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(8,'192.168.1.137');"
[2020-02-05 17:57:00.148 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580925245) WHERE id = 4;"
[2020-02-05 17:57:00.148 6824] dbquery: "UPDATE network SET numQueries = numQueries + 1300 WHERE id = 4;"
[2020-02-05 17:57:00.148 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(4,'192.168.1.112');"
[2020-02-05 17:57:00.149 6824] dbquery: "UPDATE network SET lastQuery = MAX(lastQuery, 1580904770) WHERE id = 9;"
[2020-02-05 17:57:00.149 6824] dbquery: "UPDATE network SET numQueries = numQueries + 3 WHERE id = 9;"
[2020-02-05 17:57:00.149 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(9,'192.168.1.134');"
[2020-02-05 17:57:00.149 6824] dbquery: "INSERT OR REPLACE INTO network_addresses (network_id,ip) VALUES(1,'fe80::c256:27ff:fe3b:810b');"
[2020-02-05 17:57:00.149 6824] dbquery: "COMMIT"

Thanks.

I'd like to see these lines:

for a query made by tyr (192.168.1.6). The requesting client can be found immediately above these lines where the query origin is logged.

We may need to add

DEBUG_QUERIES=true

as well in /etc/pihole/pihole-FTL.conf + pihole restartdns as well.

This one was from that particular system. I made sure to run that query. Let me know if you want to repeat with DEBUG_QUERIES.

[2020-02-05 17:57:05.479 6824] domain_in_whitelist("ads.com"): 0
[2020-02-05 17:57:05.479 6824] domain_in_blacklist("ads.com"): 0
[2020-02-05 17:57:05.480 6824] domain_in_gravity("ads.com"): 0
[2020-02-05 17:57:05.480 6824] Regex blacklist ID 1 not enabled for this client
[2020-02-05 17:57:05.480 6824] Regex blacklist ID 3 not enabled for this client
[2020-02-05 17:57:05.480 6824] Regex blacklist ID 5 not enabled for this client
[2020-02-05 17:57:05.480 6824] Regex blacklist ID 7 not enabled for this client
[2020-02-05 17:57:05.481 6824] Regex blacklist ID 9 not enabled for this client
[2020-02-05 17:57:05.481 6824] Regex blacklist ID 11 not enabled for this client
[2020-02-05 17:57:05.481 6824] Regex blacklist ID 13 not enabled for this client
[2020-02-05 17:57:05.481 6824] Regex blacklist ID 15 not enabled for this client
[2020-02-05 17:57:05.481 6824] Regex blacklist ID 17 not enabled for this client

With queries debugging:

[2020-02-05 20:33:40.095 22318] **** new UDP query[A] "ads.com" from 192.168.1.6 (ID 13, FTL 92704, src/dnsmasq/forward.c:1571)
[2020-02-05 20:33:40.095 22318] ads.com is not known
[2020-02-05 20:33:40.095 22318] domain_in_whitelist("ads.com"): 0
[2020-02-05 20:33:40.096 22318] domain_in_blacklist("ads.com"): 0
[2020-02-05 20:33:40.096 22318] domain_in_gravity("ads.com"): 0
[2020-02-05 20:33:40.096 22318] Regex blacklist ID 1 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 3 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 5 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 7 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 9 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 11 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 13 not enabled for this client
[2020-02-05 20:33:40.097 22318] Regex blacklist ID 15 not enabled for this client
[2020-02-05 20:33:40.098 22318] Regex blacklist ID 17 not enabled for this client
[2020-02-05 20:33:40.098 22318] **** forwarded ads.com to 2001:4860:4860::8844 (ID 13, src/dnsmasq/forward.c:566)
[2020-02-05 20:33:40.118 22318] ads.com is known as not to be blocked
[2020-02-05 20:33:40.118 22318] CNAME ads.com
[2020-02-05 20:33:40.118 22318] **** got reply ads.com is 104.24.98.234 (ID 13, src/dnsmasq/cache.c:487)
[2020-02-05 20:33:40.119 22318] ads.com is known as not to be blocked
[2020-02-05 20:33:40.119 22318] CNAME ads.com
[2020-02-05 20:33:40.119 22318] **** got reply ads.com is 104.24.99.234 (ID 13, src/dnsmasq/cache.c:487)
[2020-02-05 20:33:40.121 22318] **** new UDP query[AAAA] "ads.com" from 192.168.1.6 (ID 14, FTL 92705, src/dnsmasq/forward.c:1571)
[2020-02-05 20:33:40.121 22318] ads.com is known as not to be blocked
[2020-02-05 20:33:40.121 22318] **** forwarded ads.com to 2001:4860:4860::8844 (ID 14, src/dnsmasq/forward.c:566)
[2020-02-05 20:33:40.148 22318] ads.com is known as not to be blocked
[2020-02-05 20:33:40.148 22318] CNAME ads.com
[2020-02-05 20:33:40.148 22318] **** got reply ads.com is 2606:4700:3031::6818:63ea (ID 14, src/dnsmasq/cache.c:487)
[2020-02-05 20:33:40.148 22318] ads.com is known as not to be blocked
[2020-02-05 20:33:40.148 22318] CNAME ads.com
[2020-02-05 20:33:40.148 22318] **** got reply ads.com is 2606:4700:3036::6818:62ea (ID 14, src/dnsmasq/cache.c:487)
[2020-02-05 20:33:40.626 22318] **** new UDP query[A] "www.google.com" from 192.168.2.174 (ID 15, FTL 92706, src/dnsmasq/forward.c:1571)

Okay, super mysterious. I prepared a special version of FTL for you that should hopefully tell us more. Please run

pihole checkout ftl ltaub

We only add some more debugging output, there is no functional change compared to release/v5.0.

Example for new debugging output:

[2020-02-05 23:41:14.498 18960] Querying gravity database for client 127.0.0.1                                                                                                                                     
[2020-02-05 23:41:14.499 18960] Querying regex groups for client 127.0.0.1: "SELECT id from vw_regex_blacklist WHERE group_id IN (0);"                                                                             
[2020-02-05 23:41:14.499 18960] Setting regex 0 (database ID 29) to true (client 127.0.0.1)

How do these lines look like for tyr ?

Maybe I am not seeing the right thing? I don't see those lines as you expected.

My conf file is still:

PRIVACYLEVEL=0
DEBUG_DATABASE=true
DEBUG_REGEX=true
DEBUG_QUERIES=true
[2020-02-06 00:36:37.622 9901] **** new UDP query[A] "ads.com" from 192.168.1.6 (ID 23, FTL 88141, src/dnsmasq/forward.c:1571)
[2020-02-06 00:36:37.624 9901] ads.com is not known
[2020-02-06 00:36:37.624 9901] domain_in_whitelist("ads.com"): 0
[2020-02-06 00:36:37.625 9901] domain_in_blacklist("ads.com"): 0
[2020-02-06 00:36:37.626 9901] domain_in_gravity("ads.com"): 0
[2020-02-06 00:36:37.626 9901] Regex blacklist ID 1 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.627 9901] Regex blacklist ID 3 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.627 9901] Regex blacklist ID 5 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.627 9901] Regex blacklist ID 7 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.627 9901] Regex blacklist ID 9 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.628 9901] Regex blacklist ID 11 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.628 9901] Regex blacklist ID 13 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.628 9901] Regex blacklist ID 15 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.628 9901] Regex blacklist ID 17 not enabled for client 192.168.1.6
[2020-02-06 00:36:37.629 9901] **** forwarded ads.com to 2001:4860:4860::8844 (ID 23, src/dnsmasq/forward.c:566)
[2020-02-06 00:36:37.650 9901] ads.com is known as not to be blocked
[2020-02-06 00:36:37.651 9901] CNAME ads.com
[2020-02-06 00:36:37.651 9901] **** got reply ads.com is 104.24.99.234 (ID 23, src/dnsmasq/cache.c:487)
[2020-02-06 00:36:37.651 9901] ads.com is known as not to be blocked
[2020-02-06 00:36:37.651 9901] CNAME ads.com
[2020-02-06 00:36:37.652 9901] **** got reply ads.com is 104.24.98.234 (ID 23, src/dnsmasq/cache.c:487)
[2020-02-06 00:36:37.654 9901] **** new UDP query[AAAA] "ads.com" from 192.168.1.6 (ID 24, FTL 88142, src/dnsmasq/forward.c:1571)
[2020-02-06 00:36:37.654 9901] ads.com is known as not to be blocked
[2020-02-06 00:36:37.655 9901] **** forwarded ads.com to 2001:4860:4860::8844 (ID 24, src/dnsmasq/forward.c:566)
[2020-02-06 00:36:37.675 9901] ads.com is known as not to be blocked
[2020-02-06 00:36:37.675 9901] CNAME ads.com
[2020-02-06 00:36:37.675 9901] **** got reply ads.com is 2606:4700:3036::6818:62ea (ID 24, src/dnsmasq/cache.c:487)
[2020-02-06 00:36:37.676 9901] ads.com is known as not to be blocked
[2020-02-06 00:36:37.676 9901] CNAME ads.com
[2020-02-06 00:36:37.676 9901] **** got reply ads.com is 2606:4700:3031::6818:63ea (ID 24, src/dnsmasq/cache.c:487)
[2020-02-06 00:36:40.693 9901] **** new UDP query[A] "www.google.com" from 192.168.3.123 (ID 25, FTL 88143, src/dnsmasq/forward.c:1571)

Looking some more. I bolded a line that stood out to me as an error. I think I got all references to 192.168.1.6 until my first query that was blocked (as expected).

[2020-02-06 01:04:27.254 12692] ########## FTL terminated after 108575.8 ms! ##########
[2020-02-06 01:04:28.539 12939] Using log file /var/log/pihole-FTL.log
[2020-02-06 01:04:28.539 12939] ########## FTL started! ##########
[2020-02-06 01:04:28.539 12939] FTL branch: ltaub
[2020-02-06 01:04:28.539 12939] FTL version: vDev-66f0612
[2020-02-06 01:04:28.539 12939] FTL commit: 66f0612
[2020-02-06 01:04:28.539 12939] FTL date: 2020-02-05 23:41:40 +0100
[2020-02-06 01:04:28.539 12939] FTL user: pihole
[2020-02-06 01:04:28.539 12939] Compiled for armhf (compiled on CI) using arm-linux-gnueabihf-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2020-02-06 01:04:28.539 12939] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2020-02-06 01:04:28.539 12939]    SOCKET_LISTENING: only local
[2020-02-06 01:04:28.539 12939]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2020-02-06 01:04:28.539 12939]    MAXDBDAYS: max age for stored queries is 365 days
[2020-02-06 01:04:28.539 12939]    RESOLVE_IPV6: Resolve IPv6 addresses
[2020-02-06 01:04:28.539 12939]    RESOLVE_IPV4: Resolve IPv4 addresses
[2020-02-06 01:04:28.539 12939]    DBINTERVAL: saving to DB file every minute
[2020-02-06 01:04:28.539 12939]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2020-02-06 01:04:28.539 12939]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2020-02-06 01:04:28.539 12939]    PRIVACYLEVEL: Set to 0
[2020-02-06 01:04:28.539 12939]    IGNORE_LOCALHOST: Show queries from localhost
[2020-02-06 01:04:28.539 12939]    BLOCKINGMODE: Null IPs for blocked domains
[2020-02-06 01:04:28.539 12939]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2020-02-06 01:04:28.540 12939]    DBIMPORT: Importing history from database
[2020-02-06 01:04:28.540 12939]    PIDFILE: Using /var/run/pihole-FTL.pid
[2020-02-06 01:04:28.540 12939]    PORTFILE: Using /var/run/pihole-FTL.port
[2020-02-06 01:04:28.540 12939]    SOCKETFILE: Using /var/run/pihole/FTL.sock
[2020-02-06 01:04:28.540 12939]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2020-02-06 01:04:28.540 12939]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2020-02-06 01:04:28.540 12939]    GRAVITYDB: Using /etc/pihole/gravity.db
[2020-02-06 01:04:28.540 12939]    PARSE_ARP_CACHE: Active
[2020-02-06 01:04:28.540 12939]    REGEX_IGNORECASE: Disabled. Regex is case sensitive
[2020-02-06 01:04:28.540 12939]    CNAME_DEEP_INSPECT: Active
[2020-02-06 01:04:28.540 12939] *****************************
[2020-02-06 01:04:28.540 12939] * Debugging enabled         *
[2020-02-06 01:04:28.540 12939] * DEBUG_DATABASE        YES *
[2020-02-06 01:04:28.540 12939] * DEBUG_NETWORKING      NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_LOCKS           NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_QUERIES         YES *
[2020-02-06 01:04:28.540 12939] * DEBUG_FLAGS           NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_SHMEM           NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_GC              NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_ARP             NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_REGEX           YES *
[2020-02-06 01:04:28.540 12939] * DEBUG_API             NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_OVERTIME        NO  *
[2020-02-06 01:04:28.540 12939] * DEBUG_EXTBLOCKED      NO  *
[2020-02-06 01:04:28.541 12939] * DEBUG_CAPS            NO  *
[2020-02-06 01:04:28.541 12939] * DEBUG_DNSMASQ_LINES   NO  *
[2020-02-06 01:04:28.541 12939] *****************************
[2020-02-06 01:04:28.541 12939] Finished config file parsing
[2020-02-06 01:04:28.542 12939] Database version is 5
[2020-02-06 01:04:28.542 12939] Database successfully initialized
[2020-02-06 01:04:28.542 12939] DB_read_queries(): "SELECT * FROM queries WHERE timestamp >= 1580864668"
[2020-02-06 01:04:28.543 12939] New forward server: 192.168.1.1 (0/1024)
[2020-02-06 01:04:28.543 12939] New forward server: 2001:4860:4860::8888 (1/1024)
[2020-02-06 01:04:28.544 12939] New forward server: 8.8.8.8 (2/1024)
[2020-02-06 01:04:28.544 12939] New forward server: 2001:4860:4860::8844 (3/1024)
[2020-02-06 01:04:28.544 12939] New forward server: 8.8.4.4 (4/1024)
[2020-02-06 01:04:28.544 12939] Resizing "/FTL-clients" from 20480 to 40960
[2020-02-06 01:04:28.547 12939] Resizing "/FTL-strings" from 4096 to 8192
[2020-02-06 01:04:28.556 12939] Resizing "/FTL-strings" from 8192 to 12288
[2020-02-06 01:04:28.562 12939] Resizing "/FTL-queries" from 196608 to 393216
[2020-02-06 01:04:28.568 12939] Resizing "/FTL-strings" from 12288 to 16384
[2020-02-06 01:04:28.583 12939] Resizing "/FTL-strings" from 16384 to 20480
[2020-02-06 01:04:28.586 12939] Resizing "/FTL-queries" from 393216 to 589824
[2020-02-06 01:04:28.601 12939] Resizing "/FTL-strings" from 20480 to 24576
[2020-02-06 01:04:28.614 12939] Resizing "/FTL-queries" from 589824 to 786432
[2020-02-06 01:04:28.633 12939] Resizing "/FTL-strings" from 24576 to 28672
[2020-02-06 01:04:28.638 12939] Resizing "/FTL-queries" from 786432 to 983040
[2020-02-06 01:04:28.663 12939] Resizing "/FTL-queries" from 983040 to 1179648
[2020-02-06 01:04:28.673 12939] Resizing "/FTL-strings" from 28672 to 32768
[2020-02-06 01:04:28.682 12939] Resizing "/FTL-queries" from 1179648 to 1376256
[2020-02-06 01:04:28.711 12939] Resizing "/FTL-queries" from 1376256 to 1572864
[2020-02-06 01:04:28.748 12939] Resizing "/FTL-queries" from 1572864 to 1769472
[2020-02-06 01:04:28.767 12939] Resizing "/FTL-strings" from 32768 to 36864
[2020-02-06 01:04:28.783 12939] Resizing "/FTL-queries" from 1769472 to 1966080
[2020-02-06 01:04:28.824 12939] Resizing "/FTL-queries" from 1966080 to 2162688
[2020-02-06 01:04:28.843 12939] Resizing "/FTL-strings" from 36864 to 40960
[2020-02-06 01:04:28.867 12939] Resizing "/FTL-queries" from 2162688 to 2359296
[2020-02-06 01:04:28.889 12939] Resizing "/FTL-queries" from 2359296 to 2555904
[2020-02-06 01:04:28.914 12939] Resizing "/FTL-queries" from 2555904 to 2752512
[2020-02-06 01:04:28.939 12939] Resizing "/FTL-queries" from 2752512 to 2949120
[2020-02-06 01:04:28.957 12939] Resizing "/FTL-queries" from 2949120 to 3145728
[2020-02-06 01:04:28.976 12939] Resizing "/FTL-queries" from 3145728 to 3342336
[2020-02-06 01:04:28.987 12939] Resizing "/FTL-strings" from 40960 to 45056
[2020-02-06 01:04:29.007 12939] Resizing "/FTL-strings" from 45056 to 49152
[2020-02-06 01:04:29.023 12939] Resizing "/FTL-queries" from 3342336 to 3538944
[2020-02-06 01:04:29.029 12939] Resizing "/FTL-strings" from 49152 to 53248
[2020-02-06 01:04:29.073 12939] Resizing "/FTL-queries" from 3538944 to 3735552
[2020-02-06 01:04:29.117 12939] Resizing "/FTL-queries" from 3735552 to 3932160
[2020-02-06 01:04:29.160 12939] Resizing "/FTL-queries" from 3932160 to 4128768
[2020-02-06 01:04:29.162 12939] Resizing "/FTL-strings" from 53248 to 57344
[2020-02-06 01:04:29.186 12939] Resizing "/FTL-queries" from 4128768 to 4325376
[2020-02-06 01:04:29.216 12939] Imported 88732 queries from the long-term database
[2020-02-06 01:04:29.216 12939]  -> Total DNS queries: 88732
[2020-02-06 01:04:29.216 12939]  -> Cached DNS queries: 28599
[2020-02-06 01:04:29.216 12939]  -> Forwarded DNS queries: 52685
[2020-02-06 01:04:29.216 12939]  -> Exactly blocked DNS queries: 7448
[2020-02-06 01:04:29.217 12939]  -> Unknown DNS queries: 0
[2020-02-06 01:04:29.217 12939]  -> Unique domains: 2270
[2020-02-06 01:04:29.217 12939]  -> Unique clients: 50
[2020-02-06 01:04:29.217 12939]  -> Known forward destinations: 5
[2020-02-06 01:04:29.217 12939] Successfully accessed setupVars.conf
[2020-02-06 01:04:29.222 12941] PID of FTL process: 12941
[2020-02-06 01:04:29.222 12941] Listening on port 4711 for incoming IPv4 telnet connections
[2020-02-06 01:04:29.223 12941] Listening on port 4711 for incoming IPv6 telnet connections
[2020-02-06 01:04:29.223 12941] Listening on Unix socket
[2020-02-06 01:04:29.225 12941] Reloading DNS cache
[2020-02-06 01:04:29.225 12941] Blocking status is enabled
[2020-02-06 01:04:29.225 12941] *****************************
[2020-02-06 01:04:29.225 12941] * Debugging enabled         *
[2020-02-06 01:04:29.225 12941] * DEBUG_DATABASE        YES *
[2020-02-06 01:04:29.225 12941] * DEBUG_NETWORKING      NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_LOCKS           NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_QUERIES         YES *
[2020-02-06 01:04:29.225 12941] * DEBUG_FLAGS           NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_SHMEM           NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_GC              NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_ARP             NO  *
[2020-02-06 01:04:29.225 12941] * DEBUG_REGEX           YES *
[2020-02-06 01:04:29.225 12941] * DEBUG_API             NO  *
[2020-02-06 01:04:29.226 12941] * DEBUG_OVERTIME        NO  *
[2020-02-06 01:04:29.226 12941] * DEBUG_EXTBLOCKED      NO  *
[2020-02-06 01:04:29.226 12941] * DEBUG_CAPS            NO  *
[2020-02-06 01:04:29.226 12941] * DEBUG_DNSMASQ_LINES   NO  *
[2020-02-06 01:04:29.226 12941] *****************************
[2020-02-06 01:04:29.228 12941] gravityDB_open(): Successfully opened gravity.db
[2020-02-06 01:04:29.228 12941] Initializing gravity statements for 192.168.1.5
[2020-02-06 01:04:29.228 12941] Querying gravity database for client 192.168.1.5
[2020-02-06 01:04:29.228 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (5));
[2020-02-06 01:04:29.229 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (5));
[2020-02-06 01:04:29.229 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (5));
[2020-02-06 01:04:29.235 12941] Initializing gravity statements for 192.168.1.6
[2020-02-06 01:04:29.235 12941] Querying gravity database for client 192.168.1.6
[2020-02-06 01:04:29.235 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.235 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.235 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.269 12941] Querying gravity database for client 192.168.254.122
[2020-02-06 01:04:29.270 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_whitelist WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.270 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.270 12941] get_client_querystr: SELECT EXISTS(SELECT domain from vw_blacklist WHERE domain = ? AND group_id IN (0));
[2020-02-06 01:04:29.270 12941] Querying count of distinct domains in gravity database table vw_gravity
[2020-02-06 01:04:29.270 12941] gravityDB_count(SELECT value FROM info WHERE property = 'gravity_count';) - SQL error step (101): no more rows available
[2020-02-06 01:04:29.270 12941] Count of gravity domains not available. Please run pihole -g
[2020-02-06 01:04:29.271 12941] Querying count of distinct domains in gravity database table vw_regex_blacklist
[2020-02-06 01:04:29.272 12941] Querying count of distinct domains in gravity database table vw_regex_whitelist
[2020-02-06 01:04:29.273 12941] INFO: No regex whitelist entries found

[2020-02-06 01:04:29.270 12941] gravityDB_count(SELECT value FROM info WHERE property = 'gravity_count':wink: - SQL error step (101): no more rows available

[2020-02-06 01:04:29.285 12941] Querying gravity database for client 192.168.1.6
[2020-02-06 01:04:29.286 12941] Querying regex groups for client 192.168.1.6: "SELECT id from vw_regex_blacklist WHERE group_id IN (0);"
[2020-02-06 01:04:29.286 12941] Setting regex 0 (database ID 18) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 2 (database ID 19) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 4 (database ID 20) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 6 (database ID 21) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 8 (database ID 22) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 10 (database ID 23) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 12 (database ID 24) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 14 (database ID 25) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Setting regex 16 (database ID 26) to true (client 192.168.1.6)
[2020-02-06 01:04:29.286 12941] Querying gravity database for client 192.168.1.6
[2020-02-06 01:04:29.287 12941] Querying regex groups for client 192.168.1.6: "SELECT id from vw_regex_whitelist WHERE group_id IN (0);"
[2020-02-06 01:04:33.492 12941] **** new UDP query[A] "analytics.com" from 192.168.1.6 (ID 4, FTL 88735, src/dnsmasq/forward.c:1571)
[2020-02-06 01:04:33.492 12941] analytics.com is not known
[2020-02-06 01:04:33.492 12941] domain_in_whitelist("analytics.com"): 0
[2020-02-06 01:04:33.492 12941] domain_in_blacklist("analytics.com"): 0
[2020-02-06 01:04:33.493 12941] domain_in_gravity("analytics.com"): 0
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 1 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 3 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 5 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 7 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 9 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 11 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist ID 13 not enabled for client 192.168.1.6
[2020-02-06 01:04:33.493 12941] Regex blacklist (ID 25) "^analytics?[_.-]" matches "analytics.com"
[2020-02-06 01:04:33.493 12941] Blocking analytics.com as domain is regex blacklisted
[2020-02-06 01:04:33.494 12941] **** new UDP query[AAAA] "analytics.com" from 192.168.1.6 (ID 5, FTL 88736, src/dnsmasq/forward.c:1571)
[2020-02-06 01:04:33.495 12941] analytics.com is known as regex blacklisted

This is not a fatal error, it tells you in the line below what it wants you to do:


This is getting stranger and stranger... Even regex IDs are imported, odd not. Could you please send me your exact database? If we strip gravity, it should not be that large. Try

cp /etc/pihole/gravity.db ~/gravity.db
sqlite3 ~/gravity.db "DELETE FROM gravity;"
sqlite3 ~/gravity.db "VACUUM;"

This brought my gravity database down to less than 100KB. Please send it to me via PM so I can try my FTL with your database directly. Otherwise, the "what is the outcome of" might continue for a too long time. I don't want to annoy you with this bug and am thankful for all your support.

Note that you may need to put the database in a zip-container (renaming the extension may already work as well) for uploading to this server.

@ltaub Thanks for your database. I found a minor bug causing us to import regex filters multiple times when they are included in multiple groups. I fixed this now and added even more debugging output: We now log for each domain which regex matched, did not match, is disabled or is not available.

Exemplary output:

[2020-02-06 17:38:40.806 22592] **** new UDP query[A] "analytics.com" from 127.0.0.1 (ID 8, FTL 2953, src/dnsmasq/forward.c:1571)
[2020-02-06 17:38:40.806 22592] analytics.com is not known
[2020-02-06 17:38:40.807 22592] domain_in_whitelist("analytics.com"): 0
[2020-02-06 17:38:40.807 22592] domain_in_blacklist("analytics.com"): 0
[2020-02-06 17:38:40.807 22592] domain_in_gravity("analytics.com"): 0
[2020-02-06 17:38:40.807 22592] Regex blacklist (database ID 18) NO match: "analytics.com" vs. "^(.+[_.-])?adse?rv(er?|ice)?s?[0-9]*[_.-]"
[2020-02-06 17:38:40.807 22592] Regex blacklist (database ID 19) NO match: "analytics.com" vs. "^(.+[_.-])?telemetry[_.-]"
[2020-02-06 17:38:40.807 22592] Regex blacklist (database ID 20) NO match: "analytics.com" vs. "^(www[0-9]*\.)?xn--"
[2020-02-06 17:38:40.808 22592] Regex blacklist (database ID 21) NO match: "analytics.com" vs. "^adim(age|g)s?[0-9]*[_.-]"
[2020-02-06 17:38:40.808 22592] Regex blacklist (database ID 22) NO match: "analytics.com" vs. "^adtrack(er|ing)?[0-9]*[_.-]"
[2020-02-06 17:38:40.808 22592] Regex blacklist (database ID 23) NO match: "analytics.com" vs. "^advert(s|is(ing|ements?))?[0-9]*[_.-]"
[2020-02-06 17:38:40.808 22592] Regex blacklist (database ID 24) NO match: "analytics.com" vs. "^aff(iliat(es?|ion))?[_.-]"
[2020-02-06 17:38:40.808 22592] Regex blacklist (database ID 25) >> MATCH: "analytics.com" vs. "^analytics?[_.-]"
[2020-02-06 17:38:40.808 22592] Blocking analytics.com as domain is regex blacklisted

Please update and check if the situation improved for you!

1 Like

To clarify, do you want me to go back to 5.0 main or stay on ltaub for the update?

Sorry, please stay and update on ltaub for now, this is where I push the changes for our testing right now. Everything that should go into the beta branch first needs to get reviewed by the team and this takes some time.

OK - I have updated on ltaub branch. I have done a quick test and some domains that should resolve do so and likewise. I will play around some more tonight and give an update based on some deeper interaction. Thanks for your help!

2 Likes

@DL6ER is there anything you need from me?

I made some new rules and played around a bit. So far everything I do is testing out okay on my branch. Thanks again.

You can do the same testing if you like, run

pihole checkout ftl ltaub

and check if this solves the issue you've seen.

After a quick test over a VPN (I'm at work) it appears to have fixed the issue. I'll check more thoroughly later today.

1 Like