Disk shortage (/var/log/pihole/FTL.log) ahead: 99% used

thompsongeorge · September 15, 2022, 6:00am

The issue I am facing:
I got this error this morning - Disk shortage (/var/log/pihole/FTL.log ) ahead: 99% used

I recently had to completely reinstall my pi-hole setup from scratch after an OS (DietPi v8.8.1) update completely ruined the setup. The raspberry pi just wouldn't connect to the network over LAN.

I never had this issue in my first install but also I hadn't ever done a restore of blacklists and whitelists from backup ever in the past. Not sure if its related but thought I'd share the only difference/change.

I ran this...

sudo du -shc /var/log/*
0 /var/log/alternatives.log
0 /var/log/apt
0 /var/log/btmp
0 /var/log/dpkg.log
4.0K /var/log/lastlog
1.6M /var/log/lighttpd
49M /var/log/pihole
0 /var/log/pihole-FTL.log
0 /var/log/pihole.log
0 /var/log/private
4.0K /var/log/wtmp
50M total

Please note I'm not very familiar with linux.

Here's the debug log - https://tricorder.pi-hole.net/Kb2tbXKO/

Details about my system:
Raspberry Pi 4 Model B (8GB) with a 32GB SD Card.

What I have changed since installing Pi-hole:
Nothing new installed other than restoring my blacklist from backup.

jfb · September 16, 2022, 12:58am

Increase the size of your ram disk.

thompsongeorge · September 16, 2022, 10:45am

OK so this is very newbie so please bear with me... the FTL log or is the one writing to the RAM disk and that is what is running out of space?

thompsongeorge · September 16, 2022, 11:31am

Also how do I increase the size of the RAM disk?

jfb · September 16, 2022, 2:47pm

See the DietPi documentation. You might also be able to do this with the DietPi config menu.

Please post the output of the following command from the Pi terminal:

ls -lha /var/log/pihole

Your debug log did not upload normally. Please generate a new one, upload it and post the new token.

MichaIng · September 16, 2022, 4:59pm

The RAM disk size can be set in /etc/fstab, then:

mount -o remount /var/log

But I'd have a look into /var/log/pihole, which of the two log files has grown to 50 MiB within an hour, and what the last log lines are. 50 MiB is like ~100 logged lines every second, likely an error you want to resolve instead of having it eating your RAM or disk space .

Probably related to also quite large /var/log/lighttpd/error.log.

thompsongeorge · September 17, 2022, 8:15am

Token. here again - https://tricorder.pi-hole.net/k1MlEDpe/

Got this when I ran Debug
/var/log/pihole: 52.4MB used, 52.4MB total

  -----tail of FTL.log------
   [2022-09-13 18:28:30.799 364M] Resizing "FTL-strings" from 163840 to (204800 * 1) == 204800 (/dev/shm: 2.7MB used, 4.2GB total, FTL uses 2.7MB)
   [2022-09-13 18:31:37.310 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.1MB used, 52.4MB total)
   [2022-09-13 18:36:37.657 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.1MB used, 52.4MB total)
   [2022-09-13 18:41:37.020 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.2MB used, 52.4MB total)
   [2022-09-13 18:46:37.368 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.2MB used, 52.4MB total)
   [2022-09-13 18:51:37.721 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.2MB used, 52.4MB total)
   [2022-09-13 18:56:37.068 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.2MB used, 52.4MB total)
   [2022-09-13 19:01:37.421 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.3MB used, 52.4MB total)
   [2022-09-13 19:04:20.581 364M] Resizing "FTL-dns-cache" from 204800 to (13056 * 16) == 208896 (/dev/shm: 2.8MB used, 4.2GB total, FTL uses 2.7MB)
   [2022-09-13 19:06:37.777 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.3MB used, 52.4MB total)
   [2022-09-13 19:11:37.132 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:16:37.489 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:21:37.839 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:26:37.196 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:31:37.555 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:36:37.915 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:41:37.260 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:46:37.604 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:51:37.949 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 19:56:37.292 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:01:37.640 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:06:37.983 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:11:37.327 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:16:37.675 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:21:37.034 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:26:37.389 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:31:37.731 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:36:37.075 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:41:37.419 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:46:37.770 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:51:37.114 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 20:56:37.461 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 21:01:37.817 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 21:06:37.165 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/pihole: 52.4MB used, 52.4MB total)
   [2022-09-13 21:11:37.516 364/T381] WARNING: Disk shortage (/var/log/pihole/FTL.log) ahead: 99% is used (/var/log/p

Output for ls -lha /var/log/pihole

total 49M
drwxr-xr-x 2 pihole pihole 100 Sep 15 11:53 .
drwxr-xr-x 6 root   root   260 Sep  4 14:11 ..
-rw-r--r-- 1 pihole pihole 52K Sep 17 16:11 FTL.log
-rw-r----- 1 pihole pihole 49M Sep 13 19:18 pihole.log
-rw-r----- 1 root   pihole   0 Sep 17 16:10 pihole_debug.log

Hope this helps.

thompsongeorge · September 17, 2022, 8:32am

I just disabled logging and flushed and enabled logging and ran debug again...

Here's a fresh debug log after disabling flushing the pi-hole log
https://tricorder.pi-hole.net/D2k04H7x/

Ran ls -lha /var/log/pihole fresh

total 188K
drwxr-xr-x 2 pihole pihole 100 Sep 15 11:53 .
drwxr-xr-x 6 root   root   260 Sep  4 14:11 ..
-rw-r--r-- 1 pihole pihole 73K Sep 17 16:26 FTL.log
-rw-r----- 1 pihole pihole 23K Sep 17 16:33 pihole.log
-rw-r----- 1 root   pihole 87K Sep 17 16:27 pihole_debug.log

MichaIng · September 17, 2022, 8:43am

How did you disable and enable logging? pihole -l off is the default on DietPi, which disables the DNS query logging to pihole.log, while those are still logged to database anyway. Since logs are cleared on hourly basis when RAM logging is enabled, the redundant file logging doesn't make much sense.

But from the timestamps, the issue is that logs are not cleared on an hourly basis while the RAM disk is still enabled. This also explains the larger Lighttpd log. Can you check whether the hourly cron job runs without error?

journalctl -u cron
ls -l /etc/cron.hourly/dietpi
sed -n '/^[[:blank:]]*INDEX_LOGGING=/{s/^[^=]*=//p;q}' /boot/dietpi/.installed
/boot/dietpi/func/dietpi-logclear 1
ls -l /var/log

thompsongeorge · September 17, 2022, 8:58am

How did you disable and enable logging? pihole -l off

I ran - 'pihole logging off' and then 'pihole logging on'. This cleared my whole log cause it does a flush
I should have ran 'pihole logging off no flush'

I ran journalctl -u cron
-- Journal begins at Thu 2022-09-15 15:07:46 +08, ends at Sat 2022-09-17 16:47:22 +08. --
-- No entries --

Do I need to run the other commands too? Also the remaining 3 should I run them linearly?

MichaIng · September 17, 2022, 9:03am

Is cron actually running? Please check:

systemctl status cron
systemctl restart cron

And as long as you use RAM log, there is really no point in having the file DNS query logs enabled. Note that the query logs in the web UI are gathered from the database. Query logs in pihole.log are only used for the pihole -t command to show coloured logs on console.

thompsongeorge · September 17, 2022, 9:04am

-rwxr-xr-x 1 root root 1311 Aug 29 05:51 /etc/cron.hourly/dietpi

sed -n '/^[1]INDEX_LOGGING=/{s/^[2]=//p;q}' /boot/dietpi/.installed
/boot/dietpi/func/dietpi-logclear 1

sed: can't read /boot/dietpi/.installed: No such file or directory

ls -l /var/log

total 8
-rw-r--r-- 1 root     root          0 Sep  4 14:18 alternatives.log
drwxr-xr-x 2 root     root        100 Sep  4 14:18 apt
-rw-rw---- 1 root     utmp          0 Sep  4 14:26 btmp
-rw-r--r-- 1 root     root          0 Sep  4 14:18 dpkg.log
-rw-rw-r-- 1 root     utmp     292292 Sep 17 16:08 lastlog
drwxr-x--- 2 www-data www-data    100 Sep  4 14:11 lighttpd
drwxr-xr-x 2 pihole   pihole      100 Sep 15 11:53 pihole
lrwxrwxrwx 1 pihole   pihole       23 Sep  4 14:11 pihole-FTL.log -> /var/log/pihole/FTL.log
lrwxrwxrwx 1 pihole   pihole       26 Sep  4 14:11 pihole.log -> /var/log/pihole/pihole.log
drwx------ 2 root     root         40 Jul 31 23:05 private
-rw-rw-r-- 1 root     utmp       3456 Sep 17 16:08 wtmp

[:blank:] ↩︎
^= ↩︎

thompsongeorge · September 17, 2022, 9:07am

Failed to connect to bus: No such file or directory

I can do without the dashboard but I do rely on the query log regularly.

MichaIng · September 17, 2022, 9:10am

That requires root:

sudo systemctl status cron
sudo systemctl restart cron

Ay, that should exist on every DietPi system:

ls -l /boot/dietpi

Before we waste time investigating symptoms. You mentioned you needed to flash DietPi freshly after having SD card issues. Did you change the SD card? Because the symptoms, "ruined" system after an APT upgrade could mean that it is dying, i.e. getting an increasing number of bad blocks (which cannot be successfully written to), leading to various first subtile then more obvious issues. Please check the following as well, for hints on filesystem corruption:

dmesg -l emerg,alert,crit,err
ls -l /lost+found
ls -l /boot/FSCK*

MichaIng · September 17, 2022, 9:13am

You mean you do run pihole -t on the console or parse /var/log/pihole/pihole.log manually by times? Then I think RAM logging isn't suitable, since you'll only have one hour of logs in this file (not affecting the web UI/dashboard), when clearing logs works as intended.

thompsongeorge · September 17, 2022, 9:22am

Ooh my bad, yes ran it again...

sudo systemctl status cron

● cron.service
     Loaded: masked (Reason: Unit cron.service is masked.)
     Active: inactive (dead)

ls -l /boot/dietpi

total 1163
-rwxr-xr-x 1 root root  11511 Aug 29 05:51 dietpi-autostart
-rwxr-xr-x 1 root root  24254 Aug 29 05:51 dietpi-backup
-rwxr-xr-x 1 root root   7840 Aug 29 05:51 dietpi-bugreport
-rwxr-xr-x 1 root root  14521 Aug 29 05:51 dietpi-cleaner
-rwxr-xr-x 1 root root  43539 Aug 29 05:51 dietpi-cloudshell
-rwxr-xr-x 1 root root 140799 Aug 29 05:51 dietpi-config
-rwxr-xr-x 1 root root   5262 Aug 29 05:51 dietpi-cpuinfo
-rwxr-xr-x 1 root root   9386 Aug 29 05:51 dietpi-cron
-rwxr-xr-x 1 root root  16699 Aug 29 05:51 dietpi-ddns
-rwxr-xr-x 1 root root  74205 Aug 29 05:51 dietpi-drive_manager
-rwxr-xr-x 1 root root   7219 Aug 29 05:51 dietpi-explorer
-rwxr-xr-x 1 root root   3960 Aug 29 05:51 dietpi-launcher
-rwxr-xr-x 1 root root   4991 Aug 29 05:51 dietpi-led_control
-rwxr-xr-x 1 root root  21334 Aug 29 05:51 dietpi-letsencrypt
-rwxr-xr-x 1 root root   9003 Aug 29 05:51 dietpi-login
-rwxr-xr-x 1 root root   6789 Aug 29 05:51 dietpi-morsecode
-rwxr-xr-x 1 root root  35339 Aug 29 05:51 dietpi-services
-rwxr-xr-x 1 root root 674027 Aug 29 05:51 dietpi-software
-rwxr-xr-x 1 root root   7064 Aug 29 05:51 dietpi-survey
-rwxr-xr-x 1 root root  17082 Aug 29 05:51 dietpi-sync
-rwxr-xr-x 1 root root  22531 Aug 29 05:51 dietpi-update
-rwxr-xr-x 1 root root  20985 Aug 29 05:51 dietpi-vpn
drwxr-xr-x 2 root root   2048 Aug 29 05:51 func
drwxr-xr-x 2 root root    512 Aug 29 05:51 misc
-rwxr-xr-x 1 root root   2426 Aug 29 05:51 postboot
-rwxr-xr-x 1 root root   1393 Aug 29 05:51 preboot

Before we waist time investigating symptoms. You mentioned you needed to flash DietPi freshly after having SD card issues. Did you change the SD card?

No I didn't have SD card issues.. I ran a pihole update and everything was fine but I noticed a new version of dietpi, version DietPi v8.8.1 was available and I installed that but after the reboot the pi never connected back to the LAN network.. so I flashed the card and setup up the raspberry pi and pihole again.. but instead of adding the blacklists manually I imported my old blacklist from settings > teleporter.. that was the only difference between the last install and the recent one.

And 2 days ago I see this error - Disk shortage (/var/log/pihole/FTL.log ) ahead: 99% used

thompsongeorge · September 17, 2022, 9:26am

Please check the following as well, for hints on filesystem corruption:
dmesg -l emerg,alert,crit,err

[ 0.621046] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver.

sudo ls -l /lost+found

total 0

ls -l /boot/FSCK*

ls: cannot access '/boot/FSCK*': No such file or directory

jpgpi250 · September 17, 2022, 9:26am

Interesting.
Could you please list the expected output? I get:

pi@raspberrypi:~ $ dmesg -l emerg,alert,crit,err
pi@raspberrypi:~ $ sudo ls -l /lost+found
total 0
pi@raspberrypi:~ $ sudo ls -l /boot/FSCK*
ls: cannot access '/boot/FSCK*': No such file or directory
pi@raspberrypi:~ $

Thinking of adding this to my daily health report...

Is this valid for all 'pihole supported OS'? Might be an idea to add this to the debug log...

MichaIng · September 17, 2022, 9:52am

As I do not think you manually/intentionally masked that quite essential system service: Did you install anything else with a 3rd party installer or so? However, unmask it:

sudo systemctl unmask cron
sudo systemctl restart cron

Ah sorry, I forgot a flag for showing dotfiles:

ls -Al /boot/dietpi

Since the DietPi updates themselves (the ~1 MiB updated scripts) are basically noops on such a level, it was more likely due to the disk writes caused by APT package upgrades, e.g. a kernel upgrade. This can by chance go wrong in rare cases, but often it is a sign for the SD card being about to die. But no sign for any corruption on your system now, so let's not paint the devil on the wall (as we say in Germany ).

dmesg -l emerg,alert,crit,err shows kernel errors. Sadly often some or many harmless ones are shown, depending on how well the kernel is tailored for the hardware/firmware. E.g. the bcm2708_fb error on thompsongeorge's output is expected on RPi with <32 MiB GPU memory applied, reasonable on server/headless systems. The driver is tried to be loaded even that it is expected and totally fine to fail, if no GUI/desktop is used. However, "fs" or "I/O" errors can be seen as well, potentially network/adapter errors and such. Could be added to health report, but might spam it unnecessarily in cases. Most non-RPi SBCs, including vendor and e.g. Armbian kernel, show a page of kernel errors on boot, which one must ignore. More interesting are those errors logged clearly after boot, there should be a way to filter it .
A lost+found directory can be found at the root of every ext4 filesystem. fsck puts inodes there which lost their link to the filesystem, due to filesystem corruption. So if it contains anything, those files/dirs are/were missing on the filesystem, and it might be worth to do a full fsck and watch our for errors/unexpected system behaviour.
On FAT filesystems, fsck creates files with FSCK prefix on the filesystem root, AFAIK also as backups when files are successfully repaired. In most cases I've seen such files, checking the content, the original file was still there and intact. So probably less to worry, but such files shouldn't show up on a regular basis as long as you do no expect it as a result of a system crash, unclean power cycle or such.

Jep, this is the same on all Linux distros.

jfb · September 17, 2022, 1:07pm

Generally speaking, yes. But they also show details of queries, forwards and replies that are not shown in the query log.

An example is this post from a few days ago: Log entry for DNS type "TYPE5335" with reply of "BLOB" - #6 by chrislph