Pihole Docker unhealthy [solved]

n3rvino · November 22, 2023, 9:38pm

(gdb) thread 17
Thread ID 17 has terminated.

(gdb) where
#0  syscall () at ../sysdeps/unix/sysv/linux/aarch64/syscall.S:39
#1  0x0000005571de75f0 in FTL_gettid () at /__w/FTL/FTL/src/daemon.c:211
#2  0x0000005571dfb650 in is_our_lock () at /__w/FTL/FTL/src/shmem.c:465
#3  is_our_lock () at /__w/FTL/FTL/src/shmem.c:462
#4  _getDNSCache (cacheID=cacheID@entry=4825, checkMagic=checkMagic@entry=true, line=line@entry=1268, func=func@entry=0x557201bcd8 <__FUNCTION__.15060> "_FTL_check_blocking", 
    file=file@entry=0x557201be48 "/__w/FTL/FTL/src/dnsmasq_interface.c") at /__w/FTL/FTL/src/shmem.c:1148
#5  0x0000005571de8480 in _findCacheID (domainID=domainID@entry=0, clientID=clientID@entry=14391, query_type=TYPE_TXT, create_new=create_new@entry=true, 
    func=func@entry=0x557201bcd8 <__FUNCTION__.15060> "_FTL_check_blocking", line=line@entry=1268, file=file@entry=0x557201be48 "/__w/FTL/FTL/src/dnsmasq_interface.c") at /__w/FTL/FTL/src/datastructure.c:328
#6  0x0000005571dea380 in _FTL_check_blocking (queryID=queryID@entry=15408, domainID=domainID@entry=0, clientID=clientID@entry=14391, line=<optimized out>, file=<optimized out>)
    at /__w/FTL/FTL/src/dnsmasq_interface.c:1268
#7  0x0000005571dede7c in _FTL_check_blocking (file=0x557201be48 "/__w/FTL/FTL/src/dnsmasq_interface.c", line=836, clientID=14391, domainID=0, queryID=15408) at /__w/FTL/FTL/src/dnsmasq_interface.c:683
#8  _FTL_new_query (flags=flags@entry=524296, name=<optimized out>, addr=addr@entry=0x7fc2f03218, arg=0x5572020690 "query", qtype=<optimized out>, id=<optimized out>, proto=proto@entry=UDP, 
    file=file@entry=0x557202ca30 "/__w/FTL/FTL/src/dnsmasq/forward.c", line=line@entry=1771) at /__w/FTL/FTL/src/dnsmasq_interface.c:836
#9  0x0000005571e2f874 in receive_query (listen=listen@entry=0x55b124c760, now=now@entry=1700688827) at /__w/FTL/FTL/src/dnsmasq/forward.c:1770
#10 0x0000005571e203d4 in check_dns_listeners (now=now@entry=1700688827) at /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1868
#11 0x0000005571e21fd0 in main_dnsmasq (argc=<optimized out>, argv=<optimized out>) at /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1275
#12 0x0000005571de2180 in main (argc=<optimized out>, argv=0x7fc2f036c8) at /__w/FTL/FTL/src/main.c:116

DL6ER · November 22, 2023, 9:51pm

This is not nice, it shouldn't have happened...

But, okay, let's try with what we have:

github.com

pi-hole/FTL/blob/1a11413385eee8992b12b662cd37c32e55da4f6d/src/database/network-table.c#L803


      
          		}
          
          		// Get hostname and IP address of this client
          		char *hostname, *ipaddr, *interface;
          		ipaddr = strdup(getstr(client->ippos));
          		hostname = strdup(getstr(client->namepos));
          		interface = strdup(getstr(client->ifacepos));
          
          		// Skip if already handled above (first check against clients_array_size as we might have added
          		// more clients to FTL's memory herein (those known only from the database))
          		if(client_status[clientID] != CLIENT_NOT_HANDLED)
          		{
          			if(config.debug & DEBUG_ARP)
          				logg("Network table: Client %s known through ARP/neigh cache",
          				     ipaddr);
          			if(ipaddr) free(ipaddr);
          			if(hostname) free(hostname);
          			if(interface) free(interface);
          			unlock_shm();
          			continue;
          		}

This looks surprisingly similar to a bug we have fixed rather recently in the currently active Pi-hole v6.0 beta development, I didn't know we inherited it from v5.x.

I proposed a fix in branch fix/many_clients but I am not set up for doing really good testing myself for v5.x stuff anymore. It'd be awesome if you could test this in roughly half an hour from now when the binaries finished building.

Pinging almost randomly @PromoFaux @yubiuser @rdwebdesign for advise how to check out a custom FTL branch (fix/many_clients) in a Pi-hole v5.x docker container.

n3rvino · November 22, 2023, 9:56pm

Thank you so much for your time.
so I'm waiting for a fix to be released for this? can you let me know when this happens or I'll just wait for the next release.
Thanks again

yubiuser · November 22, 2023, 9:57pm

This should be possible by switching into the container

docker exec -it pihole bash

and run the checkout command

pihole checkout ftl fix/many_clients

n3rvino · November 22, 2023, 10:13pm

DL6ER · November 22, 2023, 10:18pm

This looks fine. Now we wait and that it won't crash.

n3rvino · November 22, 2023, 10:20pm

It's 20 minute on: [i] Restarting pihole-FTL service...

it's blocked?

DL6ER · November 23, 2023, 7:26am

Sorry, I went to bed when you wrote this. Did it eventually work or did you try anything else?

n3rvino · November 23, 2023, 8:28am

Me too!
today I try to regenerate the container.
I am running these tests on a test container, but if this goes well my test container will remain in production.
I give you the result later

n3rvino · November 23, 2023, 9:24am

immagine

and now?

DL6ER · November 23, 2023, 9:24am

Now we do this

n3rvino · November 23, 2023, 9:25am

ahahah

n3rvino · November 23, 2023, 9:42am

I'm sorry, but it seems that it didn't work, the docker still doesn't work and is particularly slow, I imagine for the same reason.

DL6ER · November 23, 2023, 9:45am

Could you try again to attach the gdb debugger the same way we did it above?

n3rvino · November 23, 2023, 9:47am

there is no problem

n3rvino · November 23, 2023, 10:03am

for you:

root@raspberrypi:/# sudo gdb -p $(pidof pihole-FTL)
GNU gdb (Debian 10.1-1.7) 10.1.90.20210103-git
Copyright (C) 2021 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.
Type "show copying" and "show warranty" for details.
This GDB was configured as "aarch64-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<https://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
    <http://www.gnu.org/software/gdb/documentation/>.

For help, type "help".
Type "apropos word" to search for commands related to "word".
Attaching to process 394
Reading symbols from /usr/bin/pihole-FTL...
Reading symbols from /lib/aarch64-linux-gnu/libm.so.6...
Reading symbols from /usr/lib/debug/.build-id/96/753a610bba2bd96d65892adfdb4a5246e6c754.debug...
Reading symbols from /lib/aarch64-linux-gnu/librt.so.1...
Reading symbols from /usr/lib/debug/.build-id/b5/d4628673dfea1cdf2297aac433bb9feec5f269.debug...
Reading symbols from /lib/aarch64-linux-gnu/libpthread.so.0...
Reading symbols from /usr/lib/debug/.build-id/f3/35aa4318e0d87acccf286bbf12724a53fbee8b.debug...
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/aarch64-linux-gnu/libthread_db.so.1".
Reading symbols from /lib/aarch64-linux-gnu/libc.so.6...
Reading symbols from /usr/lib/debug/.build-id/74/ed0aefe9a937a76a5d320fd24f2e01762ca277.debug...
Reading symbols from /lib/ld-linux-aarch64.so.1...
Reading symbols from /usr/lib/debug/.build-id/c9/55aebf7720fc28ce7443a0599cde62b194e7b7.debug...
Reading symbols from /lib/aarch64-linux-gnu/libnss_files.so.2...
Reading symbols from /usr/lib/debug/.build-id/d8/3acfa0cca35bafd0b0777dec2e5e6187836279.debug...
sqlite3VdbeExec (p=p@entry=0x5576d29568) at /__w/FTL/FTL/src/database/sqlite3.c:91545
91545   /__w/FTL/FTL/src/database/sqlite3.c: No such file or directory.

(gdb) continue
Continuing.
[New Thread 0x7f7ecd11e0 (LWP 661)]
[New Thread 0x7f7e4d01e0 (LWP 662)]
[New Thread 0x7f7dccf1e0 (LWP 663)]
[New Thread 0x7f7d4ce1e0 (LWP 664)]
[New Thread 0x7f7cccd1e0 (LWP 665)]
[New Thread 0x7f7c4cc1e0 (LWP 666)]
[New Thread 0x7f7bccb1e0 (LWP 667)]
[New Thread 0x7f7b4ca1e0 (LWP 668)]
[New Thread 0x7f7acc91e0 (LWP 669)]
[New Thread 0x7f7a4c81e0 (LWP 670)]
[New Thread 0x7f79cc71e0 (LWP 671)]
[New Thread 0x7f794c61e0 (LWP 672)]
[New Thread 0x7f78cc51e0 (LWP 673)]
[New Thread 0x7f784c41e0 (LWP 674)]
[New Thread 0x7f77cc31e0 (LWP 675)]
[New Thread 0x7f774c21e0 (LWP 676)]
[New Thread 0x7f76cc11e0 (LWP 677)]
[New Thread 0x7f764c01e0 (LWP 678)]

Thread 1 "pihole-FTL" received signal SIGSEGV, Segmentation fault.
sqlite3_finalize (pStmt=0x306874653030322e) at /__w/FTL/FTL/src/database/sqlite3.c:88353
88353   in /__w/FTL/FTL/src/database/sqlite3.c

(gdb) thread 1
[Switching to thread 1 (Thread 0x7f80902420 (LWP 394))]
#0  sqlite3_finalize (pStmt=0x306874653030322e) at /__w/FTL/FTL/src/database/sqlite3.c:88353
88353   /__w/FTL/FTL/src/database/sqlite3.c: No such file or directory.

(gdb) where
#0  sqlite3_finalize (pStmt=0x306874653030322e) at /__w/FTL/FTL/src/database/sqlite3.c:88353
#1  0x000000555bfd6aa8 in gravityDB_finalize_client_statements (client=0x7f7f5886e0) at /__w/FTL/FTL/src/database/gravity-db.c:952
#2  gravityDB_reload_groups (client=0x7f7f5886e0) at /__w/FTL/FTL/src/database/gravity-db.c:1252
#3  gravityDB_client_check_again (client=0x7f7f5886e0) at /__w/FTL/FTL/src/database/gravity-db.c:1272
#4  gravityDB_client_check_again (client=0x7f7f5886e0) at /__w/FTL/FTL/src/database/gravity-db.c:1261
#5  0x000000555bfd72c0 in in_whitelist (domain=0x5576d98c50 "apple.com", dns_cache=0x7f809061b0, client=0x7f7f5886e0) at /__w/FTL/FTL/src/database/gravity-db.c:1284
#6  0x000000555bfba598 in _FTL_check_blocking (queryID=queryID@entry=40967, domainID=domainID@entry=1, clientID=clientID@entry=13595, line=<optimized out>,
    file=<optimized out>) at /__w/FTL/FTL/src/dnsmasq_interface.c:1429
#7  0x000000555bfbde7c in _FTL_check_blocking (file=0x555c1edf78 "/__w/FTL/FTL/src/dnsmasq_interface.c", line=836, clientID=13595, domainID=1, queryID=40967)
    at /__w/FTL/FTL/src/dnsmasq_interface.c:683
#8  _FTL_new_query (flags=flags@entry=524296, name=<optimized out>, addr=addr@entry=0x7ff70fb988, arg=0x555c1f27d0 "query", qtype=<optimized out>, id=<optimized out>,
    proto=proto@entry=UDP, file=file@entry=0x555c1feb80 "/__w/FTL/FTL/src/dnsmasq/forward.c", line=line@entry=1771) at /__w/FTL/FTL/src/dnsmasq_interface.c:836
#9  0x000000555c000994 in receive_query (listen=listen@entry=0x5576ced3a0, now=now@entry=1700733603) at /__w/FTL/FTL/src/dnsmasq/forward.c:1770
#10 0x000000555bff14f4 in check_dns_listeners (now=now@entry=1700733603) at /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1868
#11 0x000000555bff30f0 in main_dnsmasq (argc=<optimized out>, argv=<optimized out>) at /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1275
#12 0x000000555bfb2180 in main (argc=<optimized out>, argv=0x7ff70fbe38) at /__w/FTL/FTL/src/main.c:116

DL6ER · November 23, 2023, 11:16am

The concerning bit here is that we have by now seen three crashes in three different locations and they - at first glance - are all completely independent from each other. How many clients do you have (roughly) in your network? Are they known to change very often - please also think into the direction of clients shuffling their addresses on a regular basis for increased "privacy".

edit The various places - so far - always had a connection to the whitelist...

DL6ER · November 23, 2023, 11:26am

@n3rvino I'm sorry to cause additional trouble for you but it'd probably be very helpful if you could some log files with crashes and corresponding likes with all debug options set to true as you did above:

´

n3rvino:

I find it in the previus file renamed by me:

TFL.log

[2023-11-21 09:19:01.702 388M] Opening FTL database in getNameFromIP() (/__w/FTL/FTL/src/database/network-table.c:2011)
[2023-11-21 09:19:01.708 388M]  ---> not found
[2023-11-21 09:19:01.708 388M] Closing FTL database in getNameFromIP() (/__w/FTL/FTL/src/database/network-table.c:2137)
[2023-11-21 09:19:01.709 388M] --> No result.
[2023-11-21 09:19:01.709 388M] Querying gravity database for interface of 45.225.73.193...
[2023-11-21 09:19:01.709 388M] Opening FTL database in getIfaceFromIP() (/__w/FTL/FTL/src/database/network-table.c:2153)
[2023-11-21 09:19:01.709 388M] getDatabaseHostname(): "SELECT interface FROM network JOIN network_addresses ON network_addresses.network_id = network.id WHERE network_addr>
[2023-11-21 09:19:01.710 388M] Found database interface 45.225.73.193 -> eth0
[2023-11-21 09:19:01.710 388M] Closing FTL database in getIfaceFromIP() (/__w/FTL/FTL/src/database/network-table.c:2223)
[2023-11-21 09:19:01.710 388M] Querying client table for interface :eth0
[2023-11-21 09:19:01.710 388M] --> There is no record for interface :eth0 in the client table
[2023-11-21 09:19:01.710 388M] Gravity database: Client 45.225.73.193 not found. Using default group.

[2023-11-21 09:19:01.710 388M] Adding "0" (len 2) to buffer. next_str_pos is 217743
[2023-11-21 09:19:01.710 388M] gravityDB_open(): Preparing vw_whitelist statement for client 45.225.73.193
[2023-11-21 09:19:01.710 388M] get_client_querystr: SELECT id from vw_whitelist WHERE domain = ? AND group_id IN (0);
[2023-11-21 09:19:01.710 388M] Setting sqlite3_stmt** 0x7f740264f0[9441] <-- 0x559c2c9d68
[2023-11-21 09:19:01.710 388M] gravityDB_open(): Preparing vw_gravity statement for client 45.225.73.193
[2023-11-21 09:19:01.711 388M] get_client_querystr: SELECT domain from vw_gravity WHERE domain = ? AND group_id IN (0);
[2023-11-21 09:19:01.711 388M] Setting sqlite3_stmt** 0x7f74031ef0[9441] <-- 0x559c2c8fa8
[2023-11-21 09:19:01.711 388M] gravityDB_open(): Preparing vw_blacklist statement for client 45.225.73.193
[2023-11-21 09:19:01.711 388M] get_client_querystr: SELECT id from vw_blacklist WHERE domain = ? AND group_id IN (0);
[2023-11-21 09:19:01.711 388M] Setting sqlite3_stmt** 0x7f7402bb00[9441] <-- 0x559c2ca048
[2023-11-21 09:19:01.711 388M] Getting sqlite3_stmt** 0x7f740264f0[9441] --> 0x559c2c9d68
[2023-11-21 09:19:01.711 388M] domain_in_list("cisco.com", 0x559c2c9d68, whitelist): -1
[2023-11-21 09:19:01.711 388M] Getting sqlite3_stmt** 0x7f7402bb00[9441] --> 0x559c2ca048
[2023-11-21 09:19:01.711 388M] domain_in_list("cisco.com", 0x559c2ca048, blacklist): -1
[2023-11-21 09:19:01.711 388M] Getting sqlite3_stmt** 0x7f74031ef0[9441] --> 0x559c2c8fa8
[2023-11-21 09:19:01.712 388M] domain_in_list("cisco.com", 0x559c2c8fa8, gravity): -1
[2023-11-21 09:19:01.712 388M] Checking if "cisco.com" is in gravity: no
[2023-11-21 09:19:01.712 388M] DNS cache: 45.225.73.193/cisco.com is not blocked
[2023-11-21 09:19:01.712 388M] Removed lock in _FTL_new_query() (/__w/FTL/FTL/src/dnsmasq_interface.c:842)
[2023-11-21 09:19:01.712 388M] Waiting for SHM lock in FTL_query_in_progress() (/__w/FTL/FTL/src/dnsmasq_interface.c:3247)
[2023-11-21 09:19:01.712 388/T562] Obtained SHM lock for add_FTL_clients_to_network_table() (/__w/FTL/FTL/src/database/network-table.c:778)
[2023-11-21 09:19:01.712 388/T562] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2023-11-21 09:19:01.712 388/T564]  ---> "45-165-143-20.v1bandalarga.com.br" (found externally)
[2023-11-21 09:19:01.712 388/T562] ---------------------------->  FTL crashed!  <----------------------------
[2023-11-21 09:19:01.712 388/T564] Waiting for SHM lock in resolveAndAddHostname() (/__w/FTL/FTL/src/resolve.c:364)
[2023-11-21 09:19:01.712 388/T562] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2023-11-21 09:19:01.712 388/T562] Please report a bug at https://github.com/pi-hole/FTL/issues
[2023-11-21 09:19:01.712 388/T562] and include in your report already the following details:
[2023-11-21 09:19:01.712 388/T562] FTL has been running for 1058 seconds
[2023-11-21 09:19:01.712 388/T562] FTL branch: master
[2023-11-21 09:19:01.712 388/T562] FTL version: v5.23
[2023-11-21 09:19:01.712 388/T562] FTL commit: d201776e
[2023-11-21 09:19:01.712 388/T562] FTL date: 2023-05-28 11:55:26 +0100
[2023-11-21 09:19:01.713 388/T562] FTL user: started as pihole, ended as pihole
[2023-11-21 09:19:01.713 388/T562] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 8.3.0-2) 8.3.0
[2023-11-21 09:19:01.713 388/T562] Process details: MID: 388
[2023-11-21 09:19:01.713 388/T562]                  PID: 388
[2023-11-21 09:19:01.713 388/T562]                  TID: 562
[2023-11-21 09:19:01.713 388/T562]                  Name: database
[2023-11-21 09:19:01.713 388/T562] Received signal: Segmentation fault
[2023-11-21 09:19:01.713 388/T562]      at address: 0x7f837ff000
[2023-11-21 09:19:01.713 388/T562]      with code:  SEGV_ACCERR (Invalid permissions for mapped object)

the file with more lines befor error:
FTL.txt (25.7 KB)

n3rvino · November 23, 2023, 2:38pm

FTL_extract.txt (2.6 MB)

the crach is in line number 25985 of extract log file in attach.

this is the last crash log file.

n3rvino · November 24, 2023, 5:54pm

Hi DL6ER,
have you find something in the log file uploaded by me?
thanks