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.

Sign up for GitHub

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

Jump to bottom

pihole-FTL test doesn't stop it's daemon #1064

Closed
Beanow opened this issue Feb 17, 2021 · 4 comments · Fixed by #1067
Closed

pihole-FTL test doesn't stop it's daemon #1064

Beanow opened this issue Feb 17, 2021 · 4 comments · Fixed by #1067
Labels
Bug Fixed in next release

Comments

@Beanow
Copy link

Beanow commented Feb 17, 2021 •
edited

Versions

  • Pi-hole: -
  • AdminLTE: -
  • FTL: 5.7 / master / dev branch

Platform

  • OS and version: Ubuntu 18.04
  • Platform: Docker 20.10

Expected behavior

pihole-FTL test should start and immediately stop, without needing to kill it.

This is how it's documented in pihole-FTL --help and https://docs.pi-hole.net/ftldns/in-depth/#command-line-arguments

  test            Don't start pihole-FTL but
                  instead quit immediately

test - Start FTL and process everything, but shut down immediately afterward

Actual behavior / bug

pihole-FTL test starts a daemon that doesn't exit until it receives a terminate signal.

Steps to reproduce

On a workstation that has docker installed. Use the following command from a bash terminal.

docker run --rm -i --entrypoint="bash" "pihole/pihole:v5.7" <<'EOF'
WAIT_FOR=5

pihole-FTL test

i=0
while pkill -0 pihole-FTL && [ ${i} -le 12 ]; do
    echo "pihole-FTL is running... PID: $(pgrep pihole-FTL) (${i})"
    [ ${i} -eq ${WAIT_FOR} ] && pkill pihole-FTL && echo "Sent terminate signal"
    let "i+=1"
    sleep 1
done

ps -ax
cat /var/log/pihole-FTL.log
EOF

Example of what this will output:

FTL started!
pihole-FTL is running... PID: 8 (0)
pihole-FTL is running... PID: 8 (1)
pihole-FTL is running... PID: 8 (2)
pihole-FTL is running... PID: 8 (3)
pihole-FTL is running... PID: 8 (4)
pihole-FTL is running... PID: 8 (5)
Sent terminate signal
  PID TTY      STAT   TIME COMMAND
    1 ?        Ss     0:00 bash
   38 ?        R      0:00 ps -ax
< contents of /var/log/pihole-FTL.log >
Example /var/log/pihole-FTL.log contents without DEBUG_ALL=true 
[2021-02-17 17:11:36.613 6M] ########## FTL started! ##########
[2021-02-17 17:11:36.613 6M] FTL branch: master
[2021-02-17 17:11:36.613 6M] FTL version: v5.7
[2021-02-17 17:11:36.613 6M] FTL commit: 2999e2b5
[2021-02-17 17:11:36.614 6M] FTL date: 2021-02-16 19:36:43 +0000
[2021-02-17 17:11:36.614 6M] FTL user: root
[2021-02-17 17:11:36.614 6M] Compiled for x86_64 (compiled on CI) using gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516
[2021-02-17 17:11:36.614 6M] Creating mutex
[2021-02-17 17:11:36.614 6M] Starting config file parsing (/etc/pihole/pihole-FTL.conf)
[2021-02-17 17:11:36.614 6M]    SOCKET_LISTENING: only local
[2021-02-17 17:11:36.614 6M]    AAAA_QUERY_ANALYSIS: Show AAAA queries
[2021-02-17 17:11:36.614 6M]    MAXDBDAYS: max age for stored queries is 365 days
[2021-02-17 17:11:36.614 6M]    RESOLVE_IPV6: Resolve IPv6 addresses
[2021-02-17 17:11:36.614 6M]    RESOLVE_IPV4: Resolve IPv4 addresses
[2021-02-17 17:11:36.614 6M]    DBINTERVAL: saving to DB file every minute
[2021-02-17 17:11:36.614 6M]    DBFILE: Using /etc/pihole/pihole-FTL.db
[2021-02-17 17:11:36.614 6M]    MAXLOGAGE: Importing up to 24.0 hours of log data
[2021-02-17 17:11:36.614 6M]    PRIVACYLEVEL: Set to 0
[2021-02-17 17:11:36.614 6M]    IGNORE_LOCALHOST: Show queries from localhost
[2021-02-17 17:11:36.614 6M]    BLOCKINGMODE: Null IPs for blocked domains
[2021-02-17 17:11:36.614 6M]    ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries
[2021-02-17 17:11:36.614 6M]    DBIMPORT: Importing history from database
[2021-02-17 17:11:36.614 6M]    PIDFILE: Using /run/pihole-FTL.pid
[2021-02-17 17:11:36.614 6M]    PORTFILE: Using /run/pihole-FTL.port
[2021-02-17 17:11:36.614 6M]    SOCKETFILE: Using /run/pihole/FTL.sock
[2021-02-17 17:11:36.614 6M]    SETUPVARSFILE: Using /etc/pihole/setupVars.conf
[2021-02-17 17:11:36.614 6M]    MACVENDORDB: Using /etc/pihole/macvendor.db
[2021-02-17 17:11:36.614 6M]    GRAVITYDB: Using /etc/pihole/gravity.db
[2021-02-17 17:11:36.614 6M]    PARSE_ARP_CACHE: Active
[2021-02-17 17:11:36.614 6M]    CNAME_DEEP_INSPECT: Active
[2021-02-17 17:11:36.614 6M]    DELAY_STARTUP: No delay requested.
[2021-02-17 17:11:36.614 6M]    BLOCK_ESNI: Enabled, blocking _esni.{blocked domain}
[2021-02-17 17:11:36.614 6M]    NICE: Cannot change niceness to -10 (permission denied)
[2021-02-17 17:11:36.614 6M]    MAXNETAGE: Removing IP addresses and host names from network table after 365 days
[2021-02-17 17:11:36.615 6M]    NAMES_FROM_NETDB: Enabled, trying to get names from network database
[2021-02-17 17:11:36.615 6M]    EDNS0_ECS: Overwrite client from ECS information
[2021-02-17 17:11:36.615 6M]    REFRESH_HOSTNAMES: Periodically refreshing IPv4 names
[2021-02-17 17:11:36.615 6M]    RATE_LIMIT: Rate-limiting client making more than 1000 queries in 60 seconds
[2021-02-17 17:11:36.615 6M] Finished config file parsing
[2021-02-17 17:11:36.615 6M] WARNING: Starting pihole-FTL as user root is not recommended
[2021-02-17 17:11:36.615 6M] No database file found, creating new (empty) database
[2021-02-17 17:11:36.630 6M] Database version is 1
[2021-02-17 17:11:36.630 6M] Updating long-term database to version 2
[2021-02-17 17:11:36.640 6M] Updating long-term database to version 3
[2021-02-17 17:11:36.644 6M] Updating long-term database to version 4
[2021-02-17 17:11:36.647 6M] Updating long-term database to version 5
[2021-02-17 17:11:36.650 6M] Updating long-term database to version 6
[2021-02-17 17:11:36.654 6M] Updating long-term database to version 7
[2021-02-17 17:11:36.658 6M] Updating long-term database to version 8
[2021-02-17 17:11:36.663 6M] Updating long-term database to version 9
[2021-02-17 17:11:36.668 6M] Imported 0 alias-clients
[2021-02-17 17:11:36.668 6M] Database successfully initialized
[2021-02-17 17:11:36.668 6M] Imported 0 queries from the long-term database
[2021-02-17 17:11:36.669 6M]  -> Total DNS queries: 0
[2021-02-17 17:11:36.669 6M]  -> Cached DNS queries: 0
[2021-02-17 17:11:36.669 6M]  -> Forwarded DNS queries: 0
[2021-02-17 17:11:36.669 6M]  -> Blocked DNS queries: 0
[2021-02-17 17:11:36.669 6M]  -> Unknown DNS queries: 0
[2021-02-17 17:11:36.669 6M]  -> Unique domains: 0
[2021-02-17 17:11:36.669 6M]  -> Unique clients: 0
[2021-02-17 17:11:36.669 6M]  -> Known forward destinations: 0
[2021-02-17 17:11:36.669 6M] Successfully accessed setupVars.conf
[2021-02-17 17:11:36.669 6M] *************************************************************************
[2021-02-17 17:11:36.669 6M] * WARNING: Required Linux capability CAP_NET_ADMIN not available        *
[2021-02-17 17:11:36.669 6M] *************************************************************************
[2021-02-17 17:11:36.669 6M] *************************************************************************
[2021-02-17 17:11:36.669 6M] * WARNING: Required Linux capability CAP_SYS_NICE not available         *
[2021-02-17 17:11:36.669 6M] *************************************************************************
[2021-02-17 17:11:36.671 8M] PID of FTL process: 8
[2021-02-17 17:11:36.671 8M] INFO: FTL is running as root
[2021-02-17 17:11:36.671 8/T9] Listening on port 4711 for incoming IPv4 telnet connections
[2021-02-17 17:11:36.672 8/T11] Listening on Unix socket
[2021-02-17 17:11:36.672 8M] Reloading DNS cache
[2021-02-17 17:11:36.672 8M] Blocking status is enabled
[2021-02-17 17:11:41.744 8M] Shutting down...
[2021-02-17 17:11:41.745 8M] Finished final database update
[2021-02-17 17:11:41.746 8M] ########## FTL terminated after 5s 132ms ! ##########
Example /var/log/pihole-FTL.log contents with DEBUG_ALL=true ``` [2021-02-17 17:17:22.031 6M] ########## FTL started! ########## [2021-02-17 17:17:22.031 6M] FTL branch: master [2021-02-17 17:17:22.031 6M] FTL version: v5.7 [2021-02-17 17:17:22.031 6M] FTL commit: 2999e2b [2021-02-17 17:17:22.031 6M] FTL date: 2021-02-16 19:36:43 +0000 [2021-02-17 17:17:22.031 6M] FTL user: root [2021-02-17 17:17:22.031 6M] Compiled for x86_64 (compiled on CI) using gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516 [2021-02-17 17:17:22.031 6M] Creating mutex [2021-02-17 17:17:22.031 6M] Starting config file parsing (/etc/pihole/pihole-FTL.conf) [2021-02-17 17:17:22.031 6M] SOCKET_LISTENING: only local [2021-02-17 17:17:22.031 6M] AAAA_QUERY_ANALYSIS: Show AAAA queries [2021-02-17 17:17:22.031 6M] MAXDBDAYS: max age for stored queries is 365 days [2021-02-17 17:17:22.031 6M] RESOLVE_IPV6: Resolve IPv6 addresses [2021-02-17 17:17:22.031 6M] RESOLVE_IPV4: Resolve IPv4 addresses [2021-02-17 17:17:22.031 6M] DBINTERVAL: saving to DB file every minute [2021-02-17 17:17:22.031 6M] DBFILE: Using /etc/pihole/pihole-FTL.db [2021-02-17 17:17:22.031 6M] MAXLOGAGE: Importing up to 24.0 hours of log data [2021-02-17 17:17:22.032 6M] PRIVACYLEVEL: Set to 0 [2021-02-17 17:17:22.032 6M] IGNORE_LOCALHOST: Show queries from localhost [2021-02-17 17:17:22.032 6M] BLOCKINGMODE: Null IPs for blocked domains [2021-02-17 17:17:22.032 6M] ANALYZE_ONLY_A_AND_AAAA: Disabled. Analyzing all queries [2021-02-17 17:17:22.032 6M] DBIMPORT: Importing history from database [2021-02-17 17:17:22.032 6M] PIDFILE: Using /run/pihole-FTL.pid [2021-02-17 17:17:22.032 6M] PORTFILE: Using /run/pihole-FTL.port [2021-02-17 17:17:22.032 6M] SOCKETFILE: Using /run/pihole/FTL.sock [2021-02-17 17:17:22.032 6M] SETUPVARSFILE: Using /etc/pihole/setupVars.conf [2021-02-17 17:17:22.032 6M] MACVENDORDB: Using /etc/pihole/macvendor.db [2021-02-17 17:17:22.032 6M] GRAVITYDB: Using /etc/pihole/gravity.db [2021-02-17 17:17:22.032 6M] PARSE_ARP_CACHE: Active [2021-02-17 17:17:22.032 6M] CNAME_DEEP_INSPECT: Active [2021-02-17 17:17:22.032 6M] DELAY_STARTUP: No delay requested. [2021-02-17 17:17:22.032 6M] BLOCK_ESNI: Enabled, blocking _esni.{blocked domain} [2021-02-17 17:17:22.032 6M] NICE: Cannot change niceness to -10 (permission denied) [2021-02-17 17:17:22.032 6M] MAXNETAGE: Removing IP addresses and host names from network table after 365 days [2021-02-17 17:17:22.032 6M] NAMES_FROM_NETDB: Enabled, trying to get names from network database [2021-02-17 17:17:22.032 6M] EDNS0_ECS: Overwrite client from ECS information [2021-02-17 17:17:22.032 6M] REFRESH_HOSTNAMES: Periodically refreshing IPv4 names [2021-02-17 17:17:22.032 6M] RATE_LIMIT: Rate-limiting client making more than 1000 queries in 60 seconds [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_DATABASE=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_DATABASE=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_NETWORKING=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_NETWORKING=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_LOCKS=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_LOCKS=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_QUERIES=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_QUERIES=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_FLAGS=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_FLAGS=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_SHMEM=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_SHMEM=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_GC=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_GC=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_ARP=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_ARP=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "REGEX_DEBUGMODE=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "REGEX_DEBUGMODE=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_REGEX=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_REGEX=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_API=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_API=" [2021-02-17 17:17:22.032 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.032 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_OVERTIME=" [2021-02-17 17:17:22.032 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_OVERTIME=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EXTBLOCKED=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EXTBLOCKED=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_CAPS=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_CAPS=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_DNSMASQ_LINES=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_DNSMASQ_LINES=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_VECTORS=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_VECTORS=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_RESOLVER=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_RESOLVER=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EDNS0=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EDNS0=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_CLIENTS=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_CLIENTS=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_ALIASCLIENTS=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_ALIASCLIENTS=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EVENTS=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EVENTS=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_HELPER=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_HELPER=" [2021-02-17 17:17:22.033 6M] initial: conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EXTRA=" [2021-02-17 17:17:22.033 6M] conflinebuffer = 0x55bc88e488c0, keystr = 0x55bc88e4bfe0, size = 120 [2021-02-17 17:17:22.033 6M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EXTRA=" [2021-02-17 17:17:22.033 6M] ***************************** [2021-02-17 17:17:22.033 6M] * Debugging enabled * [2021-02-17 17:17:22.033 6M] * DEBUG_DATABASE YES * [2021-02-17 17:17:22.033 6M] * DEBUG_NETWORKING YES * [2021-02-17 17:17:22.033 6M] * DEBUG_LOCKS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_QUERIES YES * [2021-02-17 17:17:22.033 6M] * DEBUG_FLAGS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_SHMEM YES * [2021-02-17 17:17:22.033 6M] * DEBUG_GC YES * [2021-02-17 17:17:22.033 6M] * DEBUG_ARP YES * [2021-02-17 17:17:22.033 6M] * DEBUG_REGEX YES * [2021-02-17 17:17:22.033 6M] * DEBUG_API YES * [2021-02-17 17:17:22.033 6M] * DEBUG_OVERTIME YES * [2021-02-17 17:17:22.033 6M] * DEBUG_EXTBLOCKED YES * [2021-02-17 17:17:22.033 6M] * DEBUG_CAPS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_DNSMASQ_LINES YES * [2021-02-17 17:17:22.033 6M] * DEBUG_VECTORS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_RESOLVER YES * [2021-02-17 17:17:22.033 6M] * DEBUG_EDNS0 YES * [2021-02-17 17:17:22.033 6M] * DEBUG_CLIENTS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_ALIASCLIENTS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_EVENTS YES * [2021-02-17 17:17:22.033 6M] * DEBUG_HELPER YES * [2021-02-17 17:17:22.033 6M] * DEBUG_EXTRA YES * [2021-02-17 17:17:22.033 6M] ***************************** [2021-02-17 17:17:22.033 6M] Finished config file parsing [2021-02-17 17:17:22.033 6M] WARNING: Starting pihole-FTL as user root is not recommended [2021-02-17 17:17:22.033 6M] No database file found, creating new (empty) database [2021-02-17 17:17:22.033 6M] dbquery: "CREATE TABLE queries ( id INTEGER PRIMARY KEY AUTOINCREMENT, timestamp INTEGER NOT NULL, type INTEGER NOT NULL, status INTEGER NOT NULL, domain TEXT NOT NULL, client TEXT NOT NULL, forward TEXT );" [2021-02-17 17:17:22.037 6M] ---> OK [2021-02-17 17:17:22.037 6M] dbquery: "CREATE INDEX idx_queries_timestamps ON queries (timestamp);" [2021-02-17 17:17:22.039 6M] ---> OK [2021-02-17 17:17:22.039 6M] dbquery: "CREATE TABLE ftl ( id INTEGER PRIMARY KEY NOT NULL, value BLOB NOT NULL );" [2021-02-17 17:17:22.041 6M] ---> OK [2021-02-17 17:17:22.041 6M] dbquery: "INSERT INTO ftl (ID,VALUE) VALUES(0,1);" [2021-02-17 17:17:22.042 6M] ---> OK [2021-02-17 17:17:22.042 6M] dbquery: "INSERT INTO ftl (ID,VALUE) VALUES(1,0);" [2021-02-17 17:17:22.044 6M] ---> OK [2021-02-17 17:17:22.044 6M] Unlocking FTL database [2021-02-17 17:17:22.044 6M] Unlocking FTL database: Success [2021-02-17 17:17:22.044 6M] Locking FTL database [2021-02-17 17:17:22.044 6M] Locking FTL database: Success [2021-02-17 17:17:22.044 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.044 6M] ---> Result 1 (int) [2021-02-17 17:17:22.044 6M] Database version is 1 [2021-02-17 17:17:22.044 6M] Updating long-term database to version 2 [2021-02-17 17:17:22.044 6M] dbquery: "CREATE TABLE counters ( id INTEGER PRIMARY KEY NOT NULL, value INTEGER NOT NULL );" [2021-02-17 17:17:22.046 6M] ---> OK [2021-02-17 17:17:22.046 6M] dbquery: "INSERT OR REPLACE INTO counters (id, value) VALUES ( 0, 0 );" [2021-02-17 17:17:22.048 6M] ---> OK [2021-02-17 17:17:22.048 6M] dbquery: "INSERT OR REPLACE INTO counters (id, value) VALUES ( 1, 0 );" [2021-02-17 17:17:22.050 6M] ---> OK [2021-02-17 17:17:22.050 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 2, 1613582242 );" [2021-02-17 17:17:22.052 6M] ---> OK [2021-02-17 17:17:22.052 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 2 );" [2021-02-17 17:17:22.054 6M] ---> OK [2021-02-17 17:17:22.054 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.054 6M] ---> Result 2 (int) [2021-02-17 17:17:22.054 6M] Updating long-term database to version 3 [2021-02-17 17:17:22.054 6M] dbquery: "CREATE TABLE network ( id INTEGER PRIMARY KEY NOT NULL, ip TEXT NOT NULL, hwaddr TEXT NOT NULL, interface TEXT NOT NULL, name TEXT, firstSeen INTEGER NOT NULL, lastQuery INTEGER NOT NULL, numQueries INTEGER NOT NULL, macVendor TEXT);" [2021-02-17 17:17:22.056 6M] ---> OK [2021-02-17 17:17:22.056 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 3 );" [2021-02-17 17:17:22.058 6M] ---> OK [2021-02-17 17:17:22.058 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.058 6M] ---> Result 3 (int) [2021-02-17 17:17:22.058 6M] Updating long-term database to version 4 [2021-02-17 17:17:22.058 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 4 );" [2021-02-17 17:17:22.059 6M] ---> OK [2021-02-17 17:17:22.059 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.059 6M] ---> Result 4 (int) [2021-02-17 17:17:22.059 6M] Updating long-term database to version 5 [2021-02-17 17:17:22.059 6M] dbquery: "PRAGMA foreign_keys=OFF" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "BEGIN TRANSACTION" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "CREATE TABLE network_addresses ( network_id INTEGER NOT NULL, ip TEXT NOT NULL, lastSeen INTEGER NOT NULL DEFAULT (cast(strftime('%s', 'now') as int)), UNIQUE(network_id,ip), FOREIGN KEY(network_id) REFERENCES network(id));" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "INSERT OR IGNORE INTO network_addresses (network_id,ip) SELECT id,ip FROM network;" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "CREATE TABLE network_bck ( id INTEGER PRIMARY KEY NOT NULL, hwaddr TEXT UNIQUE NOT NULL, interface TEXT NOT NULL, name TEXT, firstSeen INTEGER NOT NULL, lastQuery INTEGER NOT NULL, numQueries INTEGER NOT NULL, macVendor TEXT);" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "INSERT INTO network_bck SELECT id, hwaddr, interface, name, firstSeen, lastQuery, numQueries, macVendor FROM network GROUP BY hwaddr HAVING max(lastQuery);" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "DROP TABLE network;" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.060 6M] dbquery: "ALTER TABLE network_bck RENAME TO network;" [2021-02-17 17:17:22.060 6M] ---> OK [2021-02-17 17:17:22.061 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 5 );" [2021-02-17 17:17:22.061 6M] ---> OK [2021-02-17 17:17:22.061 6M] dbquery: "COMMIT" [2021-02-17 17:17:22.063 6M] ---> OK [2021-02-17 17:17:22.063 6M] dbquery: "PRAGMA foreign_keys=ON" [2021-02-17 17:17:22.063 6M] ---> OK [2021-02-17 17:17:22.063 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.063 6M] ---> Result 5 (int) [2021-02-17 17:17:22.063 6M] Updating long-term database to version 6 [2021-02-17 17:17:22.063 6M] dbquery: "CREATE TABLE message ( id INTEGER PRIMARY KEY AUTOINCREMENT, timestamp INTEGER NOT NULL, type TEXT NOT NULL, message TEXT NOT NULL, blob1 BLOB, blob2 BLOB, blob3 BLOB, blob4 BLOB, blob5 BLOB );" [2021-02-17 17:17:22.064 6M] ---> OK [2021-02-17 17:17:22.064 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 6 );" [2021-02-17 17:17:22.066 6M] ---> OK [2021-02-17 17:17:22.066 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.066 6M] ---> Result 6 (int) [2021-02-17 17:17:22.066 6M] Updating long-term database to version 7 [2021-02-17 17:17:22.066 6M] dbquery: "ALTER TABLE queries ADD COLUMN additional_info TEXT;" [2021-02-17 17:17:22.067 6M] ---> OK [2021-02-17 17:17:22.067 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 7 );" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.071 6M] ---> Result 7 (int) [2021-02-17 17:17:22.071 6M] Updating long-term database to version 8 [2021-02-17 17:17:22.071 6M] dbquery: "PRAGMA foreign_keys=OFF" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "BEGIN TRANSACTION" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "CREATE TABLE network_addresses_bck ( network_id INTEGER NOT NULL, ip TEXT UNIQUE NOT NULL, lastSeen INTEGER NOT NULL DEFAULT (cast(strftime('%s', 'now') as int)), name TEXT, nameUpdated INTEGER, FOREIGN KEY(network_id) REFERENCES network(id));" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "REPLACE INTO network_addresses_bck (network_id,ip,lastSeen) SELECT network_id,ip,lastSeen FROM network_addresses;" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "DROP TABLE network_addresses;" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "DROP TABLE IF EXISTS network_names;" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "ALTER TABLE network_addresses_bck RENAME TO network_addresses;" [2021-02-17 17:17:22.071 6M] ---> OK [2021-02-17 17:17:22.071 6M] dbquery: "CREATE TABLE network_bck ( id INTEGER PRIMARY KEY NOT NULL, hwaddr TEXT UNIQUE NOT NULL, interface TEXT NOT NULL, firstSeen INTEGER NOT NULL, lastQuery INTEGER NOT NULL, numQueries INTEGER NOT NULL, macVendor TEXT);" [2021-02-17 17:17:22.072 6M] ---> OK [2021-02-17 17:17:22.072 6M] dbquery: "INSERT INTO network_bck SELECT id, hwaddr, interface, firstSeen, lastQuery, numQueries, macVendor FROM network;" [2021-02-17 17:17:22.072 6M] ---> OK [2021-02-17 17:17:22.072 6M] dbquery: "DROP TABLE network;" [2021-02-17 17:17:22.072 6M] ---> OK [2021-02-17 17:17:22.072 6M] dbquery: "ALTER TABLE network_bck RENAME TO network;" [2021-02-17 17:17:22.072 6M] ---> OK [2021-02-17 17:17:22.072 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 8 );" [2021-02-17 17:17:22.072 6M] ---> OK [2021-02-17 17:17:22.072 6M] dbquery: "COMMIT" [2021-02-17 17:17:22.076 6M] ---> OK [2021-02-17 17:17:22.076 6M] dbquery: "PRAGMA foreign_keys=ON" [2021-02-17 17:17:22.076 6M] ---> OK [2021-02-17 17:17:22.076 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.076 6M] ---> Result 8 (int) [2021-02-17 17:17:22.076 6M] Updating long-term database to version 9 [2021-02-17 17:17:22.076 6M] dbquery: "CREATE TABLE aliasclient (id INTEGER PRIMARY KEY NOT NULL, name TEXT NOT NULL, comment TEXT);" [2021-02-17 17:17:22.080 6M] ---> OK [2021-02-17 17:17:22.080 6M] dbquery: "ALTER TABLE network ADD COLUMN aliasclient_id INTEGER;" [2021-02-17 17:17:22.083 6M] ---> OK [2021-02-17 17:17:22.083 6M] dbquery: "INSERT OR REPLACE INTO ftl (id, value) VALUES ( 0, 9 );" [2021-02-17 17:17:22.084 6M] ---> OK [2021-02-17 17:17:22.084 6M] dbquery: "SELECT VALUE FROM ftl WHERE id = 0;" [2021-02-17 17:17:22.085 6M] ---> Result 9 (int) [2021-02-17 17:17:22.085 6M] Imported 0 alias-clients [2021-02-17 17:17:22.085 6M] Unlocking FTL database [2021-02-17 17:17:22.085 6M] Unlocking FTL database: Success [2021-02-17 17:17:22.085 6M] Database successfully initialized [2021-02-17 17:17:22.085 6M] Locking FTL database [2021-02-17 17:17:22.085 6M] Locking FTL database: Success [2021-02-17 17:17:22.085 6M] DB_read_queries(): "SELECT * FROM queries WHERE timestamp >= ?" with ? = 1613495842 [2021-02-17 17:17:22.085 6M] Imported 0 queries from the long-term database [2021-02-17 17:17:22.085 6M] Unlocking FTL database [2021-02-17 17:17:22.085 6M] Unlocking FTL database: Success [2021-02-17 17:17:22.085 6M] -> Total DNS queries: 0 [2021-02-17 17:17:22.085 6M] -> Cached DNS queries: 0 [2021-02-17 17:17:22.085 6M] -> Forwarded DNS queries: 0 [2021-02-17 17:17:22.085 6M] -> Blocked DNS queries: 0 [2021-02-17 17:17:22.085 6M] -> Unknown DNS queries: 0 [2021-02-17 17:17:22.085 6M] -> Unique domains: 0 [2021-02-17 17:17:22.085 6M] -> Unique clients: 0 [2021-02-17 17:17:22.085 6M] -> Known forward destinations: 0 [2021-02-17 17:17:22.085 6M] Successfully accessed setupVars.conf [2021-02-17 17:17:22.085 6M] *************************************** [2021-02-17 17:17:22.085 6M] * Linux capability debugging enabled * [2021-02-17 17:17:22.085 6M] * CAP_CHOWN (00) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_DAC_OVERRIDE (01) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_DAC_READ_SEARCH (02) = --- * [2021-02-17 17:17:22.085 6M] * CAP_FOWNER (03) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_FSETID (04) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_KILL (05) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_SETGID (06) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_SETUID (07) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_SETPCAP (08) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_LINUX_IMMUTABLE (09) = --- * [2021-02-17 17:17:22.085 6M] * CAP_NET_BIND_SERVICE (10) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_NET_BROADCAST (11) = --- * [2021-02-17 17:17:22.085 6M] * CAP_NET_ADMIN (12) = --- * [2021-02-17 17:17:22.085 6M] * CAP_NET_RAW (13) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_IPC_LOCK (14) = --- * [2021-02-17 17:17:22.085 6M] * CAP_IPC_OWNER (15) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_MODULE (16) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_RAWIO (17) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_CHROOT (18) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_SYS_PTRACE (19) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_PACCT (20) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_ADMIN (21) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_BOOT (22) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_NICE (23) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_RESOURCE (24) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_TIME (25) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SYS_TTY_CONFIG (26) = --- * [2021-02-17 17:17:22.085 6M] * CAP_MKNOD (27) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_LEASE (28) = --- * [2021-02-17 17:17:22.085 6M] * CAP_AUDIT_WRITE (29) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_AUDIT_CONTROL (30) = --- * [2021-02-17 17:17:22.085 6M] * CAP_SETFCAP (31) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_MAC_OVERRIDE (32) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_MAC_ADMIN (33) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_SYSLOG (34) = --- * [2021-02-17 17:17:22.085 6M] * CAP_WAKE_ALARM (35) = PIE * [2021-02-17 17:17:22.085 6M] * CAP_BLOCK_SUSPEND (36) = PIE * [2021-02-17 17:17:22.086 6M] * CAP_AUDIT_READ (37) = PIE * [2021-02-17 17:17:22.086 6M] *************************************** [2021-02-17 17:17:22.086 6M] ************************************************************************* [2021-02-17 17:17:22.086 6M] * WARNING: Required Linux capability CAP_NET_ADMIN not available * [2021-02-17 17:17:22.086 6M] ************************************************************************* [2021-02-17 17:17:22.086 6M] ************************************************************************* [2021-02-17 17:17:22.086 6M] * WARNING: Required Linux capability CAP_SYS_NICE not available * [2021-02-17 17:17:22.086 6M] ************************************************************************* [2021-02-17 17:17:22.086 6M] DEBUG: argv[0] = "" [2021-02-17 17:17:22.086 6M] DEBUG: argv[1] = "-k" [2021-02-17 17:17:22.088 8M] PID of FTL process: 8 [2021-02-17 17:17:22.088 8M] INFO: FTL is running as root [2021-02-17 17:17:22.089 8/T12] Listening on Unix socket [2021-02-17 17:17:22.089 8/T11] Interface lo is IPv4 [2021-02-17 17:17:22.089 8/T11] Interface eth0 is IPv4 [2021-02-17 17:17:22.089 8/T11] Interface lo is IPv4 [2021-02-17 17:17:22.089 8/T11] Interface eth0 is IPv4 [2021-02-17 17:17:22.089 8/T11] Found 4 IPv4 and 0 IPv6 capable interfaces [2021-02-17 17:17:22.089 8/T10] Listening on port 4711 for incoming IPv4 telnet connections [2021-02-17 17:17:22.089 8M] Reloading DNS cache [2021-02-17 17:17:22.089 8M] Unlocking FTL database [2021-02-17 17:17:22.089 8M] Unlocking FTL database: already NULL [2021-02-17 17:17:22.089 8M] Unlocking FTL database: Success [2021-02-17 17:17:22.089 8M] Locking FTL database [2021-02-17 17:17:22.089 8M] Locking FTL database: Success [2021-02-17 17:17:22.089 8M] Event RELOAD_PRIVACY_LEVEL -> now SET called from FTL_dnsmasq_reload() (/root/project/src/dnsmasq_interface.c:973) [2021-02-17 17:17:22.089 8M] Blocking status is enabled [2021-02-17 17:17:22.089 8M] initial: conflinebuffer = (nil), keystr = 0x55bc88e81cb0, size = 0 [2021-02-17 17:17:22.089 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "BLOCKINGMODE=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "BLOCKINGMODE=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_DATABASE=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_DATABASE=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_NETWORKING=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_NETWORKING=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_LOCKS=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_LOCKS=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_QUERIES=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_QUERIES=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_FLAGS=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_FLAGS=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_SHMEM=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_SHMEM=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_GC=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_GC=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_ARP=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_ARP=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "REGEX_DEBUGMODE=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "REGEX_DEBUGMODE=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_REGEX=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_REGEX=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_API=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_API=" [2021-02-17 17:17:22.090 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_OVERTIME=" [2021-02-17 17:17:22.090 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.090 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_OVERTIME=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EXTBLOCKED=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EXTBLOCKED=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_CAPS=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_CAPS=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_DNSMASQ_LINES=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_DNSMASQ_LINES=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_VECTORS=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_VECTORS=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_RESOLVER=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_RESOLVER=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EDNS0=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EDNS0=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_CLIENTS=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_CLIENTS=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_ALIASCLIENTS=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_ALIASCLIENTS=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EVENTS=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EVENTS=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_HELPER=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_HELPER=" [2021-02-17 17:17:22.091 8M] initial: conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "PRIVACYLEVEL=0 " looking for "DEBUG_EXTRA=" [2021-02-17 17:17:22.091 8M] conflinebuffer = 0x55bc88e81bb0, keystr = 0x55bc88e81cb0, size = 120 [2021-02-17 17:17:22.091 8M] while reading line "DEBUG_ALL=true " looking for "DEBUG_EXTRA=" [2021-02-17 17:17:22.091 8M] ***************************** [2021-02-17 17:17:22.091 8M] * Debugging enabled * [2021-02-17 17:17:22.091 8M] * DEBUG_DATABASE YES * [2021-02-17 17:17:22.091 8M] * DEBUG_NETWORKING YES * [2021-02-17 17:17:22.091 8M] * DEBUG_LOCKS YES * [2021-02-17 17:17:22.091 8M] * DEBUG_QUERIES YES * [2021-02-17 17:17:22.092 8M] * DEBUG_FLAGS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_SHMEM YES * [2021-02-17 17:17:22.092 8M] * DEBUG_GC YES * [2021-02-17 17:17:22.092 8M] * DEBUG_ARP YES * [2021-02-17 17:17:22.092 8M] * DEBUG_REGEX YES * [2021-02-17 17:17:22.092 8M] * DEBUG_API YES * [2021-02-17 17:17:22.092 8M] * DEBUG_OVERTIME YES * [2021-02-17 17:17:22.092 8M] * DEBUG_EXTBLOCKED YES * [2021-02-17 17:17:22.092 8M] * DEBUG_CAPS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_DNSMASQ_LINES YES * [2021-02-17 17:17:22.092 8M] * DEBUG_VECTORS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_RESOLVER YES * [2021-02-17 17:17:22.092 8M] * DEBUG_EDNS0 YES * [2021-02-17 17:17:22.092 8M] * DEBUG_CLIENTS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_ALIASCLIENTS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_EVENTS YES * [2021-02-17 17:17:22.092 8M] * DEBUG_HELPER YES * [2021-02-17 17:17:22.092 8M] * DEBUG_EXTRA YES * [2021-02-17 17:17:22.092 8M] ***************************** [2021-02-17 17:17:22.092 8M] Event RELOAD_GRAVITY -> now SET called from FTL_dnsmasq_reload() (/root/project/src/dnsmasq_interface.c:997) [2021-02-17 17:17:22.092 8M] *************************************** [2021-02-17 17:17:22.092 8M] * Linux capability debugging enabled * [2021-02-17 17:17:22.092 8M] * CAP_CHOWN (00) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_DAC_OVERRIDE (01) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_DAC_READ_SEARCH (02) = --- * [2021-02-17 17:17:22.092 8M] * CAP_FOWNER (03) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_FSETID (04) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_KILL (05) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_SETGID (06) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_SETUID (07) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_SETPCAP (08) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_LINUX_IMMUTABLE (09) = --- * [2021-02-17 17:17:22.092 8M] * CAP_NET_BIND_SERVICE (10) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_NET_BROADCAST (11) = --- * [2021-02-17 17:17:22.092 8M] * CAP_NET_ADMIN (12) = --- * [2021-02-17 17:17:22.092 8M] * CAP_NET_RAW (13) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_IPC_LOCK (14) = --- * [2021-02-17 17:17:22.092 8M] * CAP_IPC_OWNER (15) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_MODULE (16) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_RAWIO (17) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_CHROOT (18) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_SYS_PTRACE (19) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_PACCT (20) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_ADMIN (21) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_BOOT (22) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_NICE (23) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_RESOURCE (24) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_TIME (25) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SYS_TTY_CONFIG (26) = --- * [2021-02-17 17:17:22.092 8M] * CAP_MKNOD (27) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_LEASE (28) = --- * [2021-02-17 17:17:22.092 8M] * CAP_AUDIT_WRITE (29) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_AUDIT_CONTROL (30) = --- * [2021-02-17 17:17:22.092 8M] * CAP_SETFCAP (31) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_MAC_OVERRIDE (32) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_MAC_ADMIN (33) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_SYSLOG (34) = --- * [2021-02-17 17:17:22.092 8M] * CAP_WAKE_ALARM (35) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_BLOCK_SUSPEND (36) = PIE * [2021-02-17 17:17:22.092 8M] * CAP_AUDIT_READ (37) = PIE * [2021-02-17 17:17:22.092 8M] *************************************** [2021-02-17 17:17:22.092 8M] ************************************************************************* [2021-02-17 17:17:22.092 8M] * WARNING: Required Linux capability CAP_NET_ADMIN not available * [2021-02-17 17:17:22.092 8M] ************************************************************************* [2021-02-17 17:17:22.092 8M] ************************************************************************* [2021-02-17 17:17:22.092 8M] * WARNING: Required Linux capability CAP_SYS_NICE not available * [2021-02-17 17:17:22.092 8M] ************************************************************************* [2021-02-17 17:17:27.160 8M] Shutting down... [2021-02-17 17:17:27.160 8M] dbquery: "BEGIN TRANSACTION IMMEDIATE" [2021-02-17 17:17:27.160 8M] ---> OK [2021-02-17 17:17:27.161 8M] dbquery: "SELECT MAX(ID) FROM queries" [2021-02-17 17:17:27.161 8M] ---> Result 0 (long long int) [2021-02-17 17:17:27.161 8M] dbquery: "END TRANSACTION" [2021-02-17 17:17:27.161 8M] ---> OK [2021-02-17 17:17:27.161 8M] Notice: Queries stored in long-term database: 0 (took 1.3 ms, last SQLite ID 0) [2021-02-17 17:17:27.161 8M] Finished final database update [2021-02-17 17:17:27.162 8M] ########## FTL terminated after 5s 130ms ! ########## ```

Note: this will very often cause a SEGV_MAPERR crash. See #1063 for that.
Logs I've included here are when this SEGV_MAPERR does not occur.

Note that the process was running in the background for the entire 6s we delayed the terminate signal for.

A similar situation occurs when running pihole-FTL -f test or pihole-FTL no-daemon test.

docker run --rm -i --entrypoint="bash" "pihole/pihole:v5.7" \
    -c "timeout -v -k10s -sTERM 6s pihole-FTL -f test > /dev/null; ps -ax"
timeout: sending signal TERM to command 'pihole-FTL'
  PID TTY      STAT   TIME COMMAND
    1 ?        Ss     0:00 bash -c timeout -v -k10s -sTERM 6s pihole-FTL -f test > /dev/null; ps -ax
   17 ?        R      0:00 ps -ax

Additional context

As part of the issue that showed up at pi-hole/docker-pi-hole#794, it was apparent that the long-term solution would be to:

  1. Use clean shutdowns instead of kill -9 and rm -f /dev/shm/FLT-*.
  2. Only actually start the pihole-FTL process when we plan on using it.

As pointed out by @DL6ER pi-hole/docker-pi-hole#794 (comment)

I should add: Cleaning up behind you is somewhat good practive and killing a process hard (without giving it even the chance to clean up properly behind itself) is never.

FTL tries to open the shared memory objects and only fails with File exists when this is not possible (in exclusive mode). FTL refuses to start as there may someone/-thing else using these files which would lead to serious issues if we'd start using them as well now.

This is actually a good thing, just the logic in the docker container has to be improved. I'm not familiar at all, but maybe the logic can be changed from

1. Starting

2. Killing

3. Staring again

To only start when we actually want it.

Looking into what pi-hole/docker-pi-hole actually does though:

Ideally that means the workflow we already have there is:

  1. pihole-FTL test
  2. pihole-FTL no-daemon

In other words, actually shutting down when running test would allow removing at least one set of kill commands that shouldn't be there.
@DL6ER
Copy link
Member

DL6ER commented Feb 17, 2021

Thanks, I've seen already that this is an issue when looking at #1063 . I have a fix ready for this and will test + push it later today.

@Beanow Beanow mentioned this issue Feb 17, 2021
Closed
@Beanow
Copy link
Author

Beanow commented Feb 17, 2021

Awesome @DL6ER :]
Additionally I tried making some automatic tests for this issue here: #1065
Since you're already on it, figured I would share it as a draft.

@DL6ER DL6ER mentioned this issue Feb 17, 2021
Merged
5 tasks
@DL6ER DL6ER linked a pull request Feb 17, 2021 that will close this issue
Fix for pihole-FTL test #1067
Merged
5 tasks
@Beanow
Copy link
Author

Beanow commented Feb 18, 2021 •
edited

Similar to #1063 I've tested the suggested fix:

# Build the suggested fix from source.
cat - > ./Dockerfile <<'EOF'
FROM pihole/ftl-build:x86_64 as build

RUN mkdir /repo
WORKDIR /repo
RUN git clone --depth 1 --branch fix/test_crash https://github.com/pi-hole/FTL.git .

ENV STATIC=""
ENV BRANCH="fix/test_crash"
ENV CIRCLE_JOB="x86_64"
RUN bash .circleci/build-CI.sh "-DSTATIC=${STATIC}" "${BRANCH}" "" "${CIRCLE_JOB}"
RUN bash test/arch_test.sh

FROM pihole/pihole:v5.7
COPY --from=build /repo/pihole-FTL /usr/bin/pihole-FTL
EOF

docker build -t pihole/pihole:fix_test_crash .
docker run --rm -i --entrypoint="bash" pihole/pihole:fix_test_crash <<'EOF'
WAIT_FOR=5

pihole-FTL test

i=0
while pkill -0 pihole-FTL && [ ${i} -le 12 ]; do
    echo "pihole-FTL is running... PID: $(pgrep pihole-FTL) (${i})"
    [ ${i} -eq ${WAIT_FOR} ] && pkill pihole-FTL && echo "Sent terminate signal"
    let "i+=1"
    sleep 1
done

ps -ax
cat /var/log/pihole-FTL.log
EOF
...
Successfully built fe8dc1c85d16
Successfully tagged pihole/pihole:fix_test_crash
FTL started!
pihole-FTL is running... PID: 8 (0)
  PID TTY      STAT   TIME COMMAND
    1 ?        Ss     0:00 bash
   19 ?        R      0:00 ps -ax
[2021-02-18 08:55:29.430 6M] ########## FTL started! ##########
[2021-02-18 08:55:29.430 6M] FTL branch: fix/test_crash
[2021-02-18 08:55:29.430 6M] FTL version: vDev-cf90185
[2021-02-18 08:55:29.430 6M] FTL commit: cf90185
[2021-02-18 08:55:29.430 6M] FTL date: 2021-02-17 20:53:34 +0100
[2021-02-18 08:55:29.430 6M] FTL user: root
[2021-02-18 08:55:29.430 6M] Compiled for x86_64 (compiled on CI) using gcc (Debian 6.3.0-18+deb9u1) 6.3.0 20170516
[2021-02-18 08:55:29.430 6M] Creating mutex
...
[2021-02-18 08:55:29.482 8/T11] Listening on Unix socket
[2021-02-18 08:55:29.484 8M] Shutting down...
[2021-02-18 08:55:29.736 8M] ########## FTL terminated after 305ms  (code 0)! ##########

In other words, it starts a daemon for <1s and shuts down 👍

I've also tried the suggested e2e tests on #1065 and they come back OK too.

@DL6ER
Copy link
Member

DL6ER commented Apr 14, 2021

The next version of FTL has been released. Please update and run

pihole checkout master

to get back on-track if you switched to a custom branch. The fix/feature branch you switched to will not receive any further updates.

Thanks for helping us to make Pi-hole better for us all!

If you have any issues, please either reopen this ticket or (preferably) create a new ticket describing the issues in further detail and only reference this ticket. This will help us to help you best.

@DL6ER DL6ER closed this as completed Apr 14, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Bug Fixed in next release
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix for pihole-FTL test pi-hole/FTL
2 participants
@Beanow @DL6ER