I ran pihole -r
meanwhile which solved another issue. I need to wait for the next entry coming up in the Pi-hole diagnosis section (typically once load is high for a few seconds) to cross-check if this issue is also gone.
Possibly related to Latest version check returns "N/A" for Pi-hole.
Clearly the database was locked for quite some time. We'll probably never find out why. This is what the dashboards currently look like AFTER running pihole -r
:
Seems to stopped working on 2022-01-07 after 02:45 in the morning. I could not find any cron job or something which ran at that time.
Interestingly the data came out fine (imported in Home Assistant) which is why I did not discover this database issue of Pi-hole earlier - and all data dropped now after running pihole -r
:
This is what's in head of pihole-FTL.log
:
[2023-01-10 00:01:01.070 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-10 00:01:01.071 22031/T22047] END TRANSACTION failed when trying to store queries to long-term database
[2023-01-10 00:01:01.071 22031/T22047] Keeping queries in memory for later new attempt
[2023-01-10 00:01:02.196 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-10 00:01:02.197 22031/T22047] WARNING: Storing devices in network table failed: database is locked
[2023-01-10 00:02:01.087 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-10 00:02:01.087 22031/T22047] END TRANSACTION failed when trying to store queries to long-term database
[2023-01-10 00:02:01.087 22031/T22047] Keeping queries in memory for later new attempt
[2023-01-10 00:02:02.208 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-10 00:02:02.208 22031/T22047] WARNING: Storing devices in network table failed: database is locked
[2023-01-10 00:03:01.110 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-10 00:03:01.110 22031/T22047] END TRANSACTION failed when trying to store queries to long-term database
Heres where the issue started (
/var/log/pihole/FTL.log.3`):
[2023-01-07 00:09:00.115 22031/T22047] Notice: Database size is 2710.27 MB, deleted 54 rows
[2023-01-07 00:20:00.065 22031/T22047] Notice: Database size is 2710.28 MB, deleted 22 rows
[2023-01-07 00:30:00.109 22031/T22047] Notice: Database size is 2710.30 MB, deleted 27 rows
[2023-01-07 00:40:00.107 22031/T22047] Notice: Database size is 2710.32 MB, deleted 126 rows
[2023-01-07 00:45:59.227 22031/T22048] WARNING: Long-term load (15min avg) larger than number of processors: 4.1 > 4
[2023-01-07 00:50:00.064 22031/T22047] Notice: Database size is 2710.37 MB, deleted 26 rows
[2023-01-07 01:00:00.104 22031/T22047] Notice: Database size is 2710.39 MB, deleted 76 rows
[2023-01-07 01:10:00.126 22031/T22047] Notice: Database size is 2710.41 MB, deleted 14 rows
[2023-01-07 01:19:00.123 22031/T22047] Notice: Database size is 2710.42 MB, deleted 5 rows
[2023-01-07 01:30:00.099 22031/T22047] Notice: Database size is 2710.46 MB, deleted 2 rows
[2023-01-07 01:31:36.845 22031M] Resizing "FTL-dns-cache" from 372736 to (23552 * 16) == 376832 (/dev/shm: 5.4MB used, 2.0GB total, FTL uses 5.4MB)
[2023-01-07 01:40:00.106 22031/T22047] Notice: Database size is 2710.50 MB, deleted 2 rows
[2023-01-07 01:50:00.089 22031/T22047] Notice: Database size is 2710.53 MB, deleted 2 rows
[2023-01-07 02:00:00.099 22031/T22047] Notice: Database size is 2710.56 MB, deleted 11 rows
[2023-01-07 02:10:00.116 22031/T22047] Notice: Database size is 2710.59 MB, deleted 2 rows
[2023-01-07 02:20:00.124 22031/T22047] Notice: Database size is 2710.60 MB, deleted 2 rows
[2023-01-07 02:30:00.050 22031/T22047] Notice: Database size is 2710.61 MB, deleted 362 rows
[2023-01-07 02:40:00.106 22031/T22047] Notice: Database size is 2710.61 MB, deleted 2 rows
[2023-01-07 02:46:00.000 22031/T22048] WARNING: Long-term load (15min avg) larger than number of processors: 5.2 > 4
[2023-01-07 02:46:00.057 22031/T22047] Encountered error while trying to store client in long-term database
[2023-01-07 02:46:00.057 22031/T22047] Statement finalization failed when trying to store queries to long-term database
[2023-01-07 02:46:00.057 22031/T22047] Error while trying to close database: database is locked
[2023-01-07 02:46:00.066 22031/T22047] SQLite3 message: database is locked in "DELETE FROM network_addresses WHERE lastSeen < 1578447960;" (5)
[2023-01-07 02:46:00.066 22031/T22047] ERROR: SQL query "DELETE FROM network_addresses WHERE lastSeen < 1578447960;" failed: database is locked (SQLITE_BUSY)
[2023-01-07 02:46:01.057 22031/T22048] add_message(type=6, message=excessive load) - SQL error step DELETE: database is locked
[2023-01-07 02:46:01.058 22031/T22048] Error while trying to close database: database is locked
[2023-01-07 02:47:01.058 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-07 02:47:01.058 22031/T22047] END TRANSACTION failed when trying to store queries to long-term database
[2023-01-07 02:47:01.058 22031/T22047] Keeping queries in memory for later new attempt
[2023-01-07 02:47:02.125 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-07 02:47:02.125 22031/T22047] WARNING: Storing devices in network table failed: database is locked
[2023-01-07 02:48:01.010 22031/T22047] ERROR: SQL query "END TRANSACTION" failed: database is locked (SQLITE_BUSY)
[2023-01-07 02:48:01.010 22031/T22047] END TRANSACTION failed when trying to store queries to long-term database
[2023-01-07 02:48:01.010 22031/T22047] Keeping queries in memory for later new attempt
So immediately after
[2023-01-07 02:46:00.000 22031/T22048] WARNING: Long-term load (15min avg) larger than number of processors: 5.2 > 4
the database went into read only / write protection mode. Interesting!
Ran sqlite3 /etc/pihole/pihole-FTL.db "PRAGMA integrity_check;"
now according to Database locked (dashboard and query log are empty) - #2 by heis2201 which took some time as the database has few gigabytes, Result: ok
.
Database lock messages in FTL log same issue.
@jfb I think there's not much left to do here, right? Debug token won't help now that everything is up and running again - and I explored all relevant logs related to the database locking (see above).
I'm just wondering how I could detect this issue in future (right in time instead of many days later by accident!)... maybe
- grep-ing the
pihole-FTL.log
regularly for the appearance ofdatabase is locked
? - Can Pi-hole run some kind of self-check and announce this issue somehow? Possibly by replacing the "Active" with "Error!" or something like that?