pihole-FTL Killed by OOM

I've had this happen a couple of times this month, where my network stops responding and when I check pihole status it says DNS not listening - doing a pihole restartdns then puts it back up and running.

Today I checked the syslog and found some exceptions and then the memory issues below.

As doing a restartdns seems to bring the system back up, is there anything I can do to make that automatic? It happened today while I was out of the house and so I wasn't too popular with those left in the house :smiley:

Jan 21 06:42:35 raspberrypi kernel: [4225227.481658] Free swap  = 0kB
Jan 21 06:42:35 raspberrypi kernel: [4225227.481663] Total swap = 102396kB
Jan 21 06:42:35 raspberrypi kernel: [4225227.481669] 49152 pages RAM
Jan 21 06:42:35 raspberrypi kernel: [4225227.481674] 0 pages HighMem/MovableOnly
Jan 21 06:42:35 raspberrypi kernel: [4225227.481678] 3359 pages reserved
Jan 21 06:42:35 raspberrypi kernel: [4225227.481683] 2048 pages cma reserved
Jan 21 06:42:35 raspberrypi kernel: [4225227.481689] Tasks state (memory values in pages):
Jan 21 06:42:35 raspberrypi kernel: [4225227.481694] [  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
Jan 21 06:42:35 raspberrypi kernel: [4225227.481731] [     80]     0    80     7957      296    61440      134             0 systemd-journal
Jan 21 06:42:35 raspberrypi kernel: [4225227.481746] [    133]     0   133     4476       12    16384      188         -1000 systemd-udevd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481763] [    205]   100   205     5599       28    24576      146             0 systemd-timesyn
Jan 21 06:42:35 raspberrypi kernel: [4225227.481777] [    247]   104   247     1635       75    14336       48          -900 dbus-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481792] [    248] 65534   248     1076        5    12288       39             0 thd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481805] [    250]     0   250      919       10    10240       40             0 alsactl
Jan 21 06:42:35 raspberrypi kernel: [4225227.481819] [    253]   108   253     1491       57    12288       53             0 avahi-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481836] [    261]     0   261     2681       12    18432       90             0 wpa_supplicant
Jan 21 06:42:35 raspberrypi kernel: [4225227.481850] [    263]   108   263     1439        3    12288       59             0 avahi-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481865] [    278]     0   278     3279       50    20480      123             0 systemd-logind
Jan 21 06:42:35 raspberrypi kernel: [4225227.481880] [    280]     0   280     7166       26    16384       12             0 rngd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481894] [    281]     0   281     1990       22    14336       32             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.481909] [    290]     0   290     6184      126    18432      131             0 rsyslogd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481923] [    396]     0   396      704       38    10240       50             0 dhcpcd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481938] [    403]   110   403     6865     1930    34816     2868             0 mosquitto
Jan 21 06:42:35 raspberrypi kernel: [4225227.481953] [    410]     0   410     2677        2    16384      143         -1000 sshd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481968] [    413]     0   413     1073        1    12288       25             0 agetty
Jan 21 06:42:35 raspberrypi kernel: [4225227.481982] [    416]     0   416     1650        2    14336       24             0 agetty
Jan 21 06:42:35 raspberrypi kernel: [4225227.481996] [    479]    33   479     2735      201    16384      250             0 lighttpd
Jan 21 06:42:35 raspberrypi kernel: [4225227.482009] [    496]   109   496   179461      257   153600    11058             0 mysqld
Jan 21 06:42:35 raspberrypi kernel: [4225227.482023] [    503]    33   503    47874        1    45056      682             0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482038] [    531]    33   531    48050      473    49152      954             0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482053] [    532]    33   532    48014      519    49152      918             0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482067] [    533]    33   533    48027      493    49152      950             0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482082] [    534]    33   534    48040      506    49152      958             0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482096] [  15921]   999 15921     3645       82    20480      146             0 systemd
Jan 21 06:42:35 raspberrypi kernel: [4225227.482110] [  15924]   999 15924     8821       46    28672      395             0 (sd-pam)
Jan 21 06:42:35 raspberrypi kernel: [4225227.482124] [  15952]   999 15952    40646    15887   190464     6408             0 pihole-FTL
Jan 21 06:42:35 raspberrypi kernel: [4225227.482142] [   1913]     0  1913      481       19     8192        0             0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482156] [   1914]     0  1914      481       22     8192        0             0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482169] [   1915]     0  1915     2469       22    16384        0             0 sort
Jan 21 06:42:35 raspberrypi kernel: [4225227.482183] [   1916]     0  1916     2469       22    16384        0             0 sort
Jan 21 06:42:35 raspberrypi kernel: [4225227.482196] [   1917]     0  1917      481       19     8192        0             0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482211] [   1929]     0  1929      481       24    10240        1             0 apt.systemd.dai
Jan 21 06:42:35 raspberrypi kernel: [4225227.482227] [   1933]     0  1933      481       25     8192        0             0 apt.systemd.dai
Jan 21 06:42:35 raspberrypi kernel: [4225227.482240] [   1949]     0  1949    13008     2041    57344        0             0 apt-get
Jan 21 06:42:35 raspberrypi kernel: [4225227.482254] [   1959]     0  1959    16198      591    43008        0             0 php7.3
Jan 21 06:42:35 raspberrypi kernel: [4225227.482268] [   1975]     0  1975     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482282] [   1983]     0  1983     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482296] [   1988]     0  1988     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482309] [   1993]     0  1993     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482323] [   1995]     0  1995     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482337] [   1996]     0  1996     1114       48    10240        0             0 modprobe
Jan 21 06:42:35 raspberrypi kernel: [4225227.482353] [   1999]     0  1999      481       38    10240        0             0 dhcpcd-run-hook
Jan 21 06:42:35 raspberrypi kernel: [4225227.482367] [   2001]     0  2001     2363       72    16384       10             0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482377] Out of memory: Kill process 15952 (pihole-FTL) score 312 or sacrifice child
Jan 21 06:42:35 raspberrypi kernel: [4225227.482474] Killed process 15952 (pihole-FTL) total-vm:162584kB, anon-rss:55876kB, file-rss:96kB, shmem-rss:7576kB
Jan 21 06:42:35 raspberrypi kernel: [4225227.609330] oom_reaper: reaped process 15952 (pihole-FTL), now anon-rss:0kB, file-rss:0kB, shmem-rss:7576kB

Raspberry Pi Model B
Pi-hole v5.3.1
Web Interface v5.5.1
FTL v5.8.1
Also running mosquitto MQTT server

Nothing has changed recently

Please upload a debug log and post just the token URL that is generated after the log is uploaded by running the following command from the Pi-hole host terminal:

pihole -d

or do it through the Web interface:

Tools > Generate Debug Log

debug token after restartdns

https://tricorder.pi-hole.net/2zoeISnt/

You are running an older version of Pi-hole that does not include this information in the debug log.

Outputs of the following please:

free -m

df -h

free -m
              total        used        free      shared  buff/cache   available
Mem:            178          51          32           6          95          68
Swap:            99          86          13
df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root        15G  4.4G  9.4G  32% /
devtmpfs         86M     0   86M   0% /dev
tmpfs            90M  3.7M   86M   5% /dev/shm
tmpfs            90M  9.4M   81M  11% /run
tmpfs           5.0M  4.0K  5.0M   1% /run/lock
tmpfs            90M     0   90M   0% /sys/fs/cgroup
/dev/mmcblk0p1  253M   53M  200M  21% /boot
tmpfs            18M     0   18M   0% /run/user/1000
tmpfs            18M     0   18M   0% /run/user/999

This is a 256 MiB RAM Raspberry Pi 1 model? I guess when some maintenance is done via cron job, like Pi-hole gravity update, this can be too close. You may be able to uninstall/disable some unneeded background processes/services and reduce RAM usage also during maintenance by looking at cron jobs, but easiest is to raise the swap file size.

Is the swap file locate on the SD card currently, and if so, are you able to attach a USB flash drive for it? That would be much better to reduce wear on the SD card and for performance.

yeah it is just an old 256 MiB Pi1 B. swap file must be on the SD card as I have no USB attached, but I must have some old USBs hanging around I could try out

FYI, I have Pi-hole (who does DHCP) and Unbound running on the same HW:

pi@ph5a:~ $ cat /proc/device-tree/model
Raspberry Pi Model B Rev 1
pi@ph5a:~ $ free -h
              total        used        free      shared  buff/cache   available
Mem:          176Mi        38Mi        51Mi       2.0Mi        86Mi        88Mi
Swap:          99Mi        41Mi        58Mi
pi@ph5a:~ $ lsb_release -a
[..]
Description:    Raspbian GNU/Linux 10 (buster)
pi@ph5a:~ $ ps -o vsize,cmd -C pihole-FTL -C unbound
   VSZ CMD
 83480 /usr/bin/pihole-FTL
 32276 /usr/sbin/unbound -d

I haven't experienced any issues so far:

pi@ph5a:~ $ zgrep -i oom_reaper /var/log/syslog*
pi@ph5a:~ $

EDIT: Should have checked kernel logs:

pi@ph5a:~ $ zgrep -i oom_reaper /var/log/{kern.log*,syslog*}
pi@ph5a:~ $

Maybe "mosquitto" is pushing it over the edge???

Actually we could have looked at the kernel output in OP, which shows quite nicely what is consuming much memory on the OOM event :smile::

Jan 21 06:42:35 raspberrypi kernel: [4225227.481694] [ pid ] uid tgid total_vm rss pgtables_bytes swapents oom_score_adj name
Jan 21 06:42:35 raspberrypi kernel: [4225227.481731] [ 80] 0 80 7957 296 61440 134 0 systemd-journal
Jan 21 06:42:35 raspberrypi kernel: [4225227.481746] [ 133] 0 133 4476 12 16384 188 -1000 systemd-udevd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481763] [ 205] 100 205 5599 28 24576 146 0 systemd-timesyn
Jan 21 06:42:35 raspberrypi kernel: [4225227.481777] [ 247] 104 247 1635 75 14336 48 -900 dbus-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481792] [ 248] 65534 248 1076 5 12288 39 0 thd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481805] [ 250] 0 250 919 10 10240 40 0 alsactl
Jan 21 06:42:35 raspberrypi kernel: [4225227.481819] [ 253] 108 253 1491 57 12288 53 0 avahi-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481836] [ 261] 0 261 2681 12 18432 90 0 wpa_supplicant
Jan 21 06:42:35 raspberrypi kernel: [4225227.481850] [ 263] 108 263 1439 3 12288 59 0 avahi-daemon
Jan 21 06:42:35 raspberrypi kernel: [4225227.481865] [ 278] 0 278 3279 50 20480 123 0 systemd-logind
Jan 21 06:42:35 raspberrypi kernel: [4225227.481880] [ 280] 0 280 7166 26 16384 12 0 rngd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481894] [ 281] 0 281 1990 22 14336 32 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.481909] [ 290] 0 290 6184 126 18432 131 0 rsyslogd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481923] [ 396] 0 396 704 38 10240 50 0 dhcpcd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481938] [ 403] 110 403 6865 1930 34816 2868 0 mosquitto
Jan 21 06:42:35 raspberrypi kernel: [4225227.481953] [ 410] 0 410 2677 2 16384 143 -1000 sshd
Jan 21 06:42:35 raspberrypi kernel: [4225227.481968] [ 413] 0 413 1073 1 12288 25 0 agetty
Jan 21 06:42:35 raspberrypi kernel: [4225227.481982] [ 416] 0 416 1650 2 14336 24 0 agetty
Jan 21 06:42:35 raspberrypi kernel: [4225227.481996] [ 479] 33 479 2735 201 16384 250 0 lighttpd
Jan 21 06:42:35 raspberrypi kernel: [4225227.482009] [ 496] 109 496 179461 257 153600 11058 0 mysqld
Jan 21 06:42:35 raspberrypi kernel: [4225227.482023] [ 503] 33 503 47874 1 45056 682 0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482038] [ 531] 33 531 48050 473 49152 954 0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482053] [ 532] 33 532 48014 519 49152 918 0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482067] [ 533] 33 533 48027 493 49152 950 0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482082] [ 534] 33 534 48040 506 49152 958 0 php-cgi
Jan 21 06:42:35 raspberrypi kernel: [4225227.482096] [ 15921] 999 15921 3645 82 20480 146 0 systemd
Jan 21 06:42:35 raspberrypi kernel: [4225227.482110] [ 15924] 999 15924 8821 46 28672 395 0 (sd-pam)
Jan 21 06:42:35 raspberrypi kernel: [4225227.482124] [ 15952] 999 15952 40646 15887 190464 6408 0 pihole-FTL
Jan 21 06:42:35 raspberrypi kernel: [4225227.482142] [ 1913] 0 1913 481 19 8192 0 0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482156] [ 1914] 0 1914 481 22 8192 0 0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482169] [ 1915] 0 1915 2469 22 16384 0 0 sort
Jan 21 06:42:35 raspberrypi kernel: [4225227.482183] [ 1916] 0 1916 2469 22 16384 0 0 sort
Jan 21 06:42:35 raspberrypi kernel: [4225227.482196] [ 1917] 0 1917 481 19 8192 0 0 sessionclean
Jan 21 06:42:35 raspberrypi kernel: [4225227.482211] [ 1929] 0 1929 481 24 10240 1 0 apt.systemd.dai
Jan 21 06:42:35 raspberrypi kernel: [4225227.482227] [ 1933] 0 1933 481 25 8192 0 0 apt.systemd.dai
Jan 21 06:42:35 raspberrypi kernel: [4225227.482240] [ 1949] 0 1949 13008 2041 57344 0 0 apt-get
Jan 21 06:42:35 raspberrypi kernel: [4225227.482254] [ 1959] 0 1959 16198 591 43008 0 0 php7.3
Jan 21 06:42:35 raspberrypi kernel: [4225227.482268] [ 1975] 0 1975 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482282] [ 1983] 0 1983 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482296] [ 1988] 0 1988 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482309] [ 1993] 0 1993 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482323] [ 1995] 0 1995 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482337] [ 1996] 0 1996 1114 48 10240 0 0 modprobe
Jan 21 06:42:35 raspberrypi kernel: [4225227.482353] [ 1999] 0 1999 481 38 10240 0 0 dhcpcd-run-hook
Jan 21 06:42:35 raspberrypi kernel: [4225227.482367] [ 2001] 0 2001 2363 72 16384 10 0 cron
Jan 21 06:42:35 raspberrypi kernel: [4225227.482377] Out of memory: Kill process 15952 (pihole-FTL) score 312 or sacrifice child

=>

109 496 179461 257 153600 11058 0 mysqld

You have a MariaDB server which takes by far most memory. It is not required for Pi-hole. There was concurrent PHP session clean and APT processes, so looks like some systemd timer and (daily?) cron job were just executed which may have caused the peak over steady memory consumption, causing the OOM killer to take action.

2 Likes

Of course :smiley:
systemd timers:

systemctl --no-pager --full -a list-timers

All default systemd timers are usually very reasonable, also the PHP session cleaning simply makes sense (when native PHP sessions are used) and does not consume much memory. Though, Pi-hole does not use PHP sessions, AFAIK (?), hence it could be disabled:

systemctl disable --now phpsessionclean.timer

EDIT: Pi-hole DOES make use of native PHP sessions, hence this timer should stay active! Else session files will fill disk or RAM (depending on where stored, usually in /var/lib/php/sessions) unlimited.

The APT processes likely come from unattended-upgrades, updating package cache and in case applying security upgrades:

dpkg -l unattended-upgrades

This is quite useful for a server, so I wouldn't disable it, as long as you do not apply APT upgrades manually on a regular basis.

I'd really check whether you require the MariaDB server at all. If you do, increase the swap file size so that steady memory consumption (excluding systemd timers and cron jobs) is around 50% of total memory, to have sufficient buffer. For this, lets first check how it is implemented:

dpkg -l dphys-swapfile

ah, now I remember installing a DB a good while ago just to have a play with - its not in active use but I guess it still runs in the background. Maybe stopping that is enough, but here is the other output mentioned above...

 $ systemctl --no-pager --full -a list-timers
NEXT                         LEFT          LAST                         PASSED    UNIT                         ACTIVATES
Sun 2022-01-23 19:39:00 GMT  17min left    Sun 2022-01-23 19:09:01 GMT  12min ago phpsessionclean.timer        phpsessionclean.service
Mon 2022-01-24 00:00:00 GMT  4h 38min left Sun 2022-01-23 00:00:02 GMT  19h ago   logrotate.timer              logrotate.service
Mon 2022-01-24 00:00:00 GMT  4h 38min left Sun 2022-01-23 00:00:02 GMT  19h ago   man-db.timer                 man-db.service
Mon 2022-01-24 02:15:26 GMT  6h left       Sun 2022-01-23 10:40:26 GMT  8h ago    apt-daily.timer              apt-daily.service
Mon 2022-01-24 06:31:35 GMT  11h left      Sun 2022-01-23 06:07:04 GMT  13h ago   apt-daily-upgrade.timer      apt-daily-upgrade.service
Mon 2022-01-24 09:54:16 GMT  14h left      Sun 2022-01-23 09:54:16 GMT  9h ago    systemd-tmpfiles-clean.timer systemd-tmpfiles-clean.service
 $ dpkg -l unattended-upgrades
dpkg-query: no packages found matching unattended-upgrades
 $ dpkg -l dphys-swapfile
Desired=Unknown/Install/Remove/Purge/Hold
| Status=Not/Inst/Conf-files/Unpacked/halF-conf/Half-inst/trig-aWait/Trig-pend
|/ Err?=(none)/Reinst-required (Status,Err: uppercase=bad)
||/ Name           Version      Architecture Description
+++-==============-============-============-=================================
ii  dphys-swapfile 20100506-5   all          Autogenerate and use a swap file

Indeed:

systemctl disable --now mariadb

No unattended-upgrades, so the apt-daily-upgrade timer/service does nothing, but apt-daily timer/service still updates the APT list/cache, which very likely is the reason for the APT processes shown in OOM killer log.

It shouldn't be required when disabling MariaDB, but in case, you can change the swap file size via /etc/dphys-swapfile and then apply via:

systemctl restart dphys-swapfile

For a Pi, you can even change the memory split if dont use any graphical desktop features etc:

gpu_mem

Specifies how much memory, in megabytes, to reserve for the exclusive use of the GPU: the remaining memory is allocated to the ARM CPU for use by the OS. For Pis with less than 1GB of memory, the default is 64; for Pis with 1GB or more of memory the default is 76.

Run sudo raspi-config and select:
Performance Options --> GPU Memory

I've just just now as an experiment changed it into 16MB.
Before:

pi@ph5a:~ $ free -h
              total        used        free      shared  buff/cache   available
Mem:          176Mi        38Mi        51Mi       2.0Mi        86Mi        88Mi
Swap:          99Mi        41Mi        58Mi

After:

pi@ph5b:~ $ free -h
               total        used        free      shared  buff/cache   available
Mem:           477Mi        43Mi       317Mi       3.0Mi       116Mi       381Mi
Swap:           99Mi          0B        99Mi

Wrong Pi, below is correct one:

pi@ph5a:~ $ free -h
              total        used        free      shared  buff/cache   available
Mem:          224Mi        38Mi        56Mi       5.0Mi       129Mi       132Mi
Swap:          99Mi          0B        99Mi
pi@ph5a:~ $ cat /boot/config.txt
[..]
gpu_mem=16

This topic was automatically closed 21 days after the last reply. New replies are no longer allowed.