Viewing Log Files - swap pager: out of swap space

Started by fromageblue, October 10, 2019, 03:22:36 PM

Previous topic - Next topic
October 10, 2019, 03:22:36 PM Last Edit: October 10, 2019, 03:40:23 PM by fromageblue
Is there a limitation on the number of lines that can be viewed on the "Firewall: Log Files: Live View page" ?
Every time I select anything in the drop down box higher than 500, the system fills up all the memory (16GB) and the swap space (8GB) which makes Opnsense crash.

It happens also if I go on the "Firewall: Log Files: Overview" page. I recently increased the log file sizes, but I still have 181G of free space which shouldn't matter since the logs are circular.

On my console screen I see:
lighttpd: (mod_openssl.c 1965) SSL (error): 5 -1 55 No buffer space available.
lighttpd: (mod_openssl.c 1975) SSL : 1 -1 error:1409F07F:SSL routines:ssl3_write_pending:bad write retry
swap pager: out of swap space


Adding some more information. Even when I view with the default setting of 25 lines in "Firewall: Log Files: Live View page", the read_log.py python script on Opnsense seems to be consuming a lot of resources which is quite high for a script that is "tail"ing only 25 lines.

root@roadblock01:~ # ps aux | grep -i python
root      94406  16.3 15.3 6582112 2541616  -  R    10:07     0:01.70 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      26892   0.0  0.0   28524       0  -  IWs  -         0:00.00 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py (python3.7)
root      28642   0.0  7.3 2117472 1216480  -  R    10:07     0:00.67 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      71640   0.0  0.0   49528    7572  -  S    09:30     0:02.50 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py console (python3.7)
root       3729   0.0  0.0 1058012    2112  0  S+   10:07     0:00.00 grep -i python

root@roadblock01:~ # ps aux | grep -i python
root       8113  26.8 23.7 6582112 3942392  -  R    10:07     0:03.14 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      77508  18.7 12.7 2121568 2112428  -  R    10:07     0:02.10 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      52577  10.4 13.3 3166304 2206828  -  R    10:07     0:01.11 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root      12578   0.0  0.1   20320   13284  -  R    10:07     0:00.01 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root      26892   0.0  0.0   28524       0  -  IWs  -         0:00.00 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py (python3.7)
root      71640   0.0  0.0   49536    8120  -  S    09:30     0:02.51 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py console (python3.7)
root      87119   0.0  0.1   20320   13308  -  S    10:07     0:00.30 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root      88518   0.0  0.0 1058012    2108  0  S+   10:07     0:00.00 grep -i python

root@roadblock01:~ # ps aux | grep -i python
root      77508  41.2 37.1 6582112 6179568  -  R    10:07     0:05.23 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      52577  34.9 31.7 6582368 5276964  -  R    10:07     0:04.25 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root      87119  27.3 22.7 6582368 3779992  -  R    10:07     0:03.17 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root       3147  19.6 17.3 3166304 2883564  -  R    10:08     0:02.18 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest e2b4b16bbe3bc9456b54a5c5e6c5772a (python3.7)
root      86562   9.9  2.0 2117728  326088  -  R    10:08     0:01.04 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest e2b4b16bbe3bc9456b54a5c5e6c5772a (python3.7)
root      26892   0.0  0.0   28524       0  -  IWs  -         0:00.00 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py (python3.7)
root      71640   0.0  0.0   49540    8276  -  S    09:30     0:02.52 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py console (python3.7)
root      16992   0.0  0.0 1058012    1920  0  R+   10:08     0:00.31 grep -i python

root@roadblock01:~ # ps aux | grep -i python
root      77508  32.9 37.2 6582112 6184096  -  D    10:07     0:05.38 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest (python3.7)
root      52577  28.0 31.7 6582368 5281112  -  D    10:07     0:04.39 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root      87119  22.3 22.7 6582368 3783576  -  D    10:07     0:03.32 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest 4ee52e8b7986a693008cff3a9dc47c86 (python3.7)
root       3147  16.3 17.4 3166304 2887520  -  D    10:08     0:02.31 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest e2b4b16bbe3bc9456b54a5c5e6c5772a (python3.7)
root      86562   8.7  2.0 2117728  333616  -  D    10:08     0:01.18 /usr/local/bin/python3 /usr/local/opnsense/scripts/filter/read_log.py /limit 25 /digest e2b4b16bbe3bc9456b54a5c5e6c5772a (python3.7)
root      26892   0.0  0.0   28524       0  -  IWs  -         0:00.00 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py (python3.7)
root      71640   0.0  0.0   49540       0  -  SW   -         0:00.00 /usr/local/bin/python3 /usr/local/opnsense/service/configd.py console (python3.7)
root      38298   0.0  0.0    9432    1892  0  R+   10:08     0:00.01 grep -i python

For those reading this post, I found a workaround. On the "Firewall: Log Files: Live View" page, if I select 500 lines (or more) than uncheck the "auto refresh" option after 3-4 seconds, the server doesn't run out of memory anymore and the results will be displayed.

From what I can see on the command line, the "auto refresh" options keeps spawning new forks of "read_log.py" ever X number of seconds even if there is already a "read_log.py" process running on the system. On a small 500KB log file, the process will complete quite fast, but since my logs are set to 1GB, the "read_log.py" takes much longer to process the log.

The issue is the "auto-refresh" option keeps spawning new "read_log.py" processes before the last one had time to finish, therefore the system can quickly become overloaded and run out of memory. The "read_log.py" needs a check to prevent multiple copies of itself from running at the same time.

My python skills are not that good to attempt an adequate fix... looking for help.