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

Running PADD v3.8.0 crashed FTL #1394

Closed
yubiuser opened this issue Jul 27, 2022 · 9 comments
Closed

Running PADD v3.8.0 crashed FTL #1394

yubiuser opened this issue Jul 27, 2022 · 9 comments
Labels
Fixed in next release

Comments

@yubiuser
Copy link
Member

Versions

rockpi@rockpi-4b:~$ pihole -v
  Pi-hole version is removeblockpagefunctionality v5.11.4-23-g5fe0f30b (Latest: v5.11.4)
  AdminLTE version is devel v5.13-43-g62fe7768 (Latest: v5.13)
  FTL version is new/god vDev-2b6b943 (Latest: v5.16.1)

Actual behavior / bug

Running PADD v3.8.0 crashed FTL

[2022-07-27 11:23:28.942 26105/T10782] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:23:28.942 26105/T10782] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:23:28.942 26105/T10782] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:24:34.416 26105/T12866] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Connection reset by peer
[2022-07-27 11:24:34.417 26105/T12866] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:24:34.417 26105/T12866] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:24:34.417 26105/T12866] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Connection reset by peer
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:34.464 26105M] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2022-07-27 11:25:34.465 26105M] ---------------------------->  FTL crashed!  <----------------------------
[2022-07-27 11:25:34.465 26105M] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2022-07-27 11:25:34.465 26105M] Please report a bug at https://github.com/pi-hole/FTL/issues
[2022-07-27 11:25:34.465 26105M] and include in your report already the following details:
[2022-07-27 11:25:34.465 26105M] FTL has been running for 40383 seconds
[2022-07-27 11:25:34.465 26105M] FTL branch: new/god
[2022-07-27 11:25:34.465 26105M] FTL version: vDev-2b6b943
[2022-07-27 11:25:34.465 26105M] FTL commit: 2b6b943
[2022-07-27 11:25:34.465 26105M] FTL date: 2022-07-09 21:21:21 +0200
[2022-07-27 11:25:34.465 26105M] FTL user: started as pihole, ended as pihole
[2022-07-27 11:25:34.465 26105M] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2022-07-27 11:25:34.465 26105M] Process details: MID: 26105
[2022-07-27 11:25:34.465 26105M]                  PID: 26105
[2022-07-27 11:25:34.465 26105M]                  TID: 26105
[2022-07-27 11:25:34.465 26105M]                  Name: pihole-FTL
[2022-07-27 11:25:34.465 26105M] Received signal: Segmentation fault
[2022-07-27 11:25:34.465 26105M]      at address: (nil)
[2022-07-27 11:25:34.465 26105M]      with code:  SEGV_MAPERR (Address not mapped to object)
[2022-07-27 11:25:34.466 26105M] Backtrace:
[2022-07-27 11:25:34.466 26105M] B[0000]: /usr/bin/pihole-FTL(generate_backtrace+0x4c) [0xaaaae0431c2c]
[2022-07-27 11:25:34.498 26105M] L[0000]: /__w/FTL/FTL/src/signals.c:98
[2022-07-27 11:25:34.504 26105M] B[0001]: /usr/bin/pihole-FTL(+0x620e8) [0xaaaae04320e8]
[2022-07-27 11:25:34.536 26105M] L[0001]: /__w/FTL/FTL/src/signals.c:242
[2022-07-27 11:25:34.542 26105M] B[0002]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0xffff8b0e8788]
[2022-07-27 11:25:34.542 26105M] ------ Listing content of directory /dev/shm ------
[2022-07-27 11:25:34.542 26105M] File Mode User:Group      Size  Filename
[2022-07-27 11:25:34.542 26105M] rwxrwxrwx root:root       260  .
[2022-07-27 11:25:34.542 26105M] rwxr-xr-x root:root         4K  ..
[2022-07-27 11:25:34.542 26105M] rw------- pihole:pihole     4K  FTL-per-client-regex
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole    41K  FTL-dns-cache
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole     8K  FTL-overTime
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole     2M  FTL-queries
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole   315K  FTL-upstreams
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole    86K  FTL-clients
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole    37K  FTL-domains
[2022-07-27 11:25:34.543 26105M] rw------- pihole:pihole    82K  FTL-strings
[2022-07-27 11:25:34.544 26105M] rw------- pihole:pihole    12  FTL-settings
[2022-07-27 11:25:34.544 26105M] rw------- pihole:pihole   244  FTL-counters
[2022-07-27 11:25:34.544 26105M] rw------- pihole:pihole   104  FTL-lock
[2022-07-27 11:25:34.544 26105M] ---------------------------------------------------
@DL6ER
Copy link
Member

DL6ER commented Jul 27, 2022

I just tried to reproduce this (also on FTL branch new/god) and am not seeing even a single of these Broken pipe or Connection reset by peer warnings you are seeing. Not even after having it running for several minutes.
Despite the fact that PADD is thinking my CPU is at 115.5°C, everything seems perfectly fine.

However, looking at the timestamps, it also doesn't seem likely that a connection prematurely closed by PADD would have caused the crash at hand. Unfortunately, the backtrace is useless. Can you trigger the crash reliably?

@CalSchilling
Copy link

I believe I was having the same issue after running PADD certain devices would lose internet and tracing it back to the pihole. Attempted to pihole -up and it would get an error when the update got to FTL (sorry i closed all of my putty screens so I can't give the exact error)

I fixed it by rebooting my pihole and re-downloading PADD from their GitHub. I also ran a repair on pihole. Again I can't remember the command as I closed putty and can't remember the exact commands.

@yubiuser
Copy link
Member Author 

[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Connection reset by peer
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe
[2022-07-27 11:25:07.254 26105/T13901] WARN: Could not write() everything in ssend() [/__w/FTL/FTL/src/api/socket.c:245]: Broken pipe

This part should be mitigated by pi-hole/PADD#254

@yubiuser
Copy link
Member Author

Does this help?

[2022-07-29 18:49:17.696 11428M] Resizing "FTL-dns-cache" from 4096 to (512 * 16) == 8192 (/dev/shm: 1.9MB used, 2.0GB total, FTL uses 1.9MB)
[2022-07-29 18:51:50.486 11428M] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2022-07-29 18:51:50.486 11428M] ---------------------------->  FTL crashed!  <----------------------------
[2022-07-29 18:51:50.486 11428M] !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
[2022-07-29 18:51:50.486 11428M] Please report a bug at https://github.com/pi-hole/FTL/issues
[2022-07-29 18:51:50.486 11428M] and include in your report already the following details:
[2022-07-29 18:51:50.486 11428M] FTL has been running for 409 seconds
[2022-07-29 18:51:50.486 11428M] FTL branch: new/god
[2022-07-29 18:51:50.486 11428M] FTL version: vDev-2b6b943
[2022-07-29 18:51:50.486 11428M] FTL commit: 2b6b943
[2022-07-29 18:51:50.486 11428M] FTL date: 2022-07-09 21:21:21 +0200
[2022-07-29 18:51:50.486 11428M] FTL user: started as pihole, ended as pihole
[2022-07-29 18:51:50.486 11428M] Compiled for aarch64 (compiled on CI) using aarch64-linux-gnu-gcc (Debian 6.3.0-18) 6.3.0 20170516
[2022-07-29 18:51:50.486 11428M] Process details: MID: 11428
[2022-07-29 18:51:50.486 11428M]                  PID: 11428
[2022-07-29 18:51:50.486 11428M]                  TID: 11428
[2022-07-29 18:51:50.486 11428M]                  Name: pihole-FTL
[2022-07-29 18:51:50.486 11428M] Received signal: Segmentation fault
[2022-07-29 18:51:50.486 11428M]      at address: 0xffff01003ce9
[2022-07-29 18:51:50.486 11428M]      with code:  SEGV_MAPERR (Address not mapped to object)
[2022-07-29 18:51:50.487 11428M] Backtrace:
[2022-07-29 18:51:50.487 11428M] B[0000]: /usr/bin/pihole-FTL(generate_backtrace+0x4c) [0xaaaab58c1c2c]
[2022-07-29 18:51:50.521 11428M] L[0000]: /__w/FTL/FTL/src/signals.c:98
[2022-07-29 18:51:50.526 11428M] B[0001]: /usr/bin/pihole-FTL(+0x620e8) [0xaaaab58c20e8]
[2022-07-29 18:51:50.559 11428M] L[0001]: /__w/FTL/FTL/src/signals.c:242
[2022-07-29 18:51:50.563 11428M] B[0002]: linux-vdso.so.1(__kernel_rt_sigreturn+0) [0xffffad2f2788]
[2022-07-29 18:51:50.563 11428M] B[0003]: /usr/bin/pihole-FTL(+0x1a3ed4) [0xaaaab5a03ed4]
[2022-07-29 18:51:50.670 11428M] L[0003]: /__w/FTL/FTL/src/database/sqlite3.c:34666
[2022-07-29 18:51:50.682 11428M] B[0004]: /usr/bin/pihole-FTL(+0x6ba44) [0xaaaab58cba44]
[2022-07-29 18:51:50.717 11428M] L[0004]: /__w/FTL/FTL/src/database/gravity-db.c:279
[2022-07-29 18:51:50.722 11428M] B[0005]: /usr/bin/pihole-FTL(gravityDB_prepare_client_statements+0x3f0) [0xaaaab58cd580]
[2022-07-29 18:51:50.757 11428M] L[0005]: /__w/FTL/FTL/src/database/gravity-db.c:857
[2022-07-29 18:51:50.763 11428M] B[0006]: /usr/bin/pihole-FTL(in_whitelist+0x184) [0xaaaab58ce01c]
[2022-07-29 18:51:50.799 11428M] L[0006]: /__w/FTL/FTL/src/database/gravity-db.c:1223
[2022-07-29 18:51:50.803 11428M] B[0007]: /usr/bin/pihole-FTL(+0x50114) [0xaaaab58b0114]
[2022-07-29 18:51:50.838 11428M] L[0007]: /__w/FTL/FTL/src/dnsmasq_interface.c:1415
[2022-07-29 18:51:50.844 11428M] B[0008]: /usr/bin/pihole-FTL(_FTL_new_query+0xad0) [0xaaaab58b1a30]
[2022-07-29 18:51:50.879 11428M] L[0008]: /__w/FTL/FTL/src/dnsmasq_interface.c:1238
[2022-07-29 18:51:50.883 11428M] B[0009]: /usr/bin/pihole-FTL(receive_query+0x434) [0xaaaab58f228c]
[2022-07-29 18:51:50.919 11428M] L[0009]: /__w/FTL/FTL/src/dnsmasq/forward.c:1624 (discriminator 4)
[2022-07-29 18:51:50.923 11428M] B[0010]: /usr/bin/pihole-FTL(+0x876c8) [0xaaaab58e76c8]
[2022-07-29 18:51:50.960 11428M] L[0010]: /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1862
[2022-07-29 18:51:50.964 11428M] B[0011]: /usr/bin/pihole-FTL(main_dnsmasq+0xcf8) [0xaaaab58e8e58]
[2022-07-29 18:51:51.002 11428M] L[0011]: /__w/FTL/FTL/src/dnsmasq/dnsmasq.c:1273
[2022-07-29 18:51:51.007 11428M] B[0012]: /usr/bin/pihole-FTL(main+0x1f0) [0xaaaab58a70c0]
[2022-07-29 18:51:51.040 11428M] L[0012]: /__w/FTL/FTL/src/main.c:124
[2022-07-29 18:51:51.045 11428M] B[0013]: /lib/aarch64-linux-gnu/libc.so.6(__libc_start_main+0xe4) [0xffffad06ed24]
[2022-07-29 18:51:51.045 11428M] B[0014]: /usr/bin/pihole-FTL(+0x471b8) [0xaaaab58a71b8]
[2022-07-29 18:51:51.087 11428M] L[0014]: :?
[2022-07-29 18:51:51.094 11428M] ------ Listing content of directory /dev/shm ------
[2022-07-29 18:51:51.094 11428M] File Mode User:Group      Size  Filename
[2022-07-29 18:51:51.094 11428M] rwxrwxrwx root:root       260  .
[2022-07-29 18:51:51.094 11428M] rwxr-xr-x root:root         4K  ..
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole     4K  FTL-per-client-regex
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole     8K  FTL-dns-cache
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole     8K  FTL-overTime
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole     1M  FTL-queries
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole   315K  FTL-upstreams
[2022-07-29 18:51:51.094 11428M] rw------- pihole:pihole    86K  FTL-clients
[2022-07-29 18:51:51.095 11428M] rw------- pihole:pihole    37K  FTL-domains
[2022-07-29 18:51:51.095 11428M] rw------- pihole:pihole    82K  FTL-strings
[2022-07-29 18:51:51.095 11428M] rw------- pihole:pihole    12  FTL-settings
[2022-07-29 18:51:51.095 11428M] rw------- pihole:pihole   244  FTL-counters
[2022-07-29 18:51:51.095 11428M] rw------- pihole:pihole   104  FTL-lock
[2022-07-29 18:51:51.095 11428M] ---------------------------------------------------
[2022-07-29 18:51:51.095 11428M] Please also include some lines from above the !!!!!!!!! header.
[2022-07-29 18:51:51.095 11428M] Thank you for helping us to improve our FTL engine!
[2022-07-29 18:51:51.095 11428M] Waiting for threads to join
[2022-07-29 18:51:51.095 11428M] Thread telnet-IPv4 (0) is idle, terminating it.
[2022-07-29 18:51:51.095 11428M] Thread telnet-socket (2) is idle, terminating it.
[2022-07-29 18:51:51.096 11428M] Thread database (3) is idle, terminating it.
[2022-07-29 18:51:51.096 11428M] Thread housekeeper (4) is idle, terminating it.
[2022-07-29 18:51:51.096 11428M] Thread DNS client (5) is idle, terminating it.
[2022-07-29 18:51:51.097 11428M] All threads joined

@jbutters110
Copy link

I just tried to reproduce this (also on FTL branch new/god) and am not seeing even a single of these Broken pipe or Connection reset by peer warnings you are seeing. Not even after having it running for several minutes. Despite the fact that PADD is thinking my CPU is at 115.5°C, everything seems perfectly fine.

However, looking at the timestamps, it also doesn't seem likely that a connection prematurely closed by PADD would have caused the crash at hand. Unfortunately, the backtrace is useless. Can you trigger the crash reliably?

I can trigger this issue reliably, the issue only begins to manifest after several hours of normal operation, I.e. after a couple of hours FTL.log will begin to grow with the socket error message.

@DL6ER
Copy link
Member

DL6ER commented Jul 31, 2022 •
edited
Loading

@yubiuser The crash was here

FTL/src/database/gravity-db.c

Line 278 in 2b6b943

int rc = sqlite3_prepare_v2(gravity_db, querystr, -1, &table_stmt, NULL);

and then in SQLITE_PRIVATE int sqlite3SafetyCheckOk(sqlite3 *db) at sqlite3.c:34666 (Github gives error 500 when trying to generate a direct link) when it tries to get a property of the database pointer which, apparently, is 0xffff01003ce9 (not NULL). Maybe the database object was freed but the pointer wasn't set to NULL. However, the only code where this could happen inside FTL is

FTL/src/database/gravity-db.c

Lines 969 to 970 in 5ff5bed

sqlite3_close(gravity_db);
gravity_db = NULL;

where gravity_db is set to NULL.

Maybe this is an SQLite3 bug, but I don't see how we can end up with Address not mapped to object here. Tracing this down might be a complex endeavor, can you somehow force this to happen?

@yubiuser
Copy link
Member Author

can you somehow force this to happen?

No I can't it happend during stress-testing the API. While trying really hard and often, FTL only crashed twice with the above backtraces. With the re-written API code I don't expect any of those crashed to happen again.

@yubiuser
Copy link
Member Author

yubiuser commented Aug 4, 2022

Fixed by #1396

@yubiuser yubiuser mentioned this issue Aug 12, 2022
Closed
@yubiuser
Copy link
Member Author

Fix released with https://github.com/pi-hole/FTL/releases/tag/v5.16.2

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
Fixed in next release
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@CalSchilling @DL6ER @yubiuser @jbutters110