Continuously increasing memory usage since the update to 2.6

[stephenw10]

@techniker_ctr said in Continuously increasing memory usage since the update to 2.6:

I will run these until I can determine a failure.

It may well not fail, just start freeing unused memory when it gets close.
It would be interesting to see.

Steve

[bingo600]

I think i can see (On pfSense+)

A continuous slow growth too , i have 8GB Ram , and am now on 36% used.
I tried to stop ntopng, and wait a few minutes ... It fell to 34%

I noticed a kazillion filterdns processes in Diagnostic --> System Activity

login-to-view

I tried to see the in a CLI with : ps -aux (i'm a linux guy) - But they're not shown with that command.

What cli command will show those filterdns processes And the many ntopng's i see too.

Edit:
I have a DOH blocklist loaded via web , does that create a filterdns per "host" or ??

/Bingo

[stephenw10]

Yes, it can create a lot of filterdns processes. Especially if some things are failing to resolve.
Check the Resolver logs for errors. Prune any old entries that no longer resolve if you can.

[bingo600]

@stephenw10
I see no resolver errors
Everything is resolvable.

How does that resolverstuff work ?
Is it a timed job that spawns a resolver for every entry ?

Is it run every 10 min ?

/Bingo

[stephenw10]

Every 5mins by default:
https://docs.netgate.com/pfsense/en/latest/config/advanced-firewall-nat.html#aliases-hostnames-resolve-interval

[bingo600]

Well to reply (to my self) on how to list the filterdns processes threads (process number is the same)

jimp gave a hint here
https://redmine.pfsense.org/issues/8758

Use

ps uxHaww | grep filterdns

root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
root    62928   0.0  0.2  82100  14760  -  Is   Wed16      0:00.00 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
[22.01-RELEASE][admin@..]/root: ps uxHaww | grep filterdns | wc
     132    2501   20780

Sending the output to wc shows 132 line matches , that seems to be in (Is) "Idle state"

The file : /var/etc/filterdns.conf seems to contain my DNS resolvable aliases , and i have 66 of these.

[22.01-RELEASE][admin@..../root: cat /var/etc/filterdns.conf | wc
      66     198    2832

Strange that the # of filterdns processes threads are excactly the double of the DNS entries in /var/etc/filterdns.conf
But i suppose there is a tech (OS) reason for that , since it's excactly double, and i just don't know enough of the inner work.

Now to find out how Netgate gets the "filterdns" DNS name shown in the Diagnostics --> System Activity

ps uxHaww | grep filterdns

Doesn't show the DNS name to be resolved.
@jimp - Any hint here ?

62928 root         20    0    80M    14M uwait    0   0:00   0.00% /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1{bigdata.adsunflower}
62928 root         20    0    80M    14M uwait    2   0:00   0.00% /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1{choice.microsoft.co}

Well beside the filterdns processes threads being the double # of the /var/etc/filterdns.conf entries , I see no increase in processes threads etc. So my guess is that the filterdns stuff is behaving as expected , and not causing memory growth , unless you add more entries to resolve.

/Bingo

[stephenw10]

That output is from top -aSH you should be able to see them there. Though you are limited by the terminal size.

Steve

[Techniker_ctr]

@stephenw10

Greetings,

I ran our test systems for a while and it seems that the RAM has settled at around 90%. This is not optimal, as we cannot use our monitoring effectively with such high values.

So far, I have not been able to detect any failure due to the increase in RAM consumption.

I have now deployed a test system with 2 GB RAM to see whether the RAM increase settles back at 90% or whether it remains at around 50%. After the deployment, the RAM on the test system is at 26%. I would provide feedback if I have any further information on this.

In the meantime, do you have any other ideas about the reason for the continuous increase in RAM?

[stephenw10]

Still no obvious process with increasing usage?

[Techniker_ctr]

@stephenw10

Not that i can see, here is the same system output side by side:

System as posted before:

top:
Before:
login-to-view

Today:
login-to-view

All I see is an increase in the "wired" memory

htop:
Before:
login-to-view

Today:
login-to-view

telegraf needs even less RAM than in the last analysis, I suspect that telegraf did just not compiled any data at this point.

Therefore, I do not see any really meaningful indications as to why the RAM is rising.

[stephenw10]

What does that usage look like in the pfSense monitoring graphs?

On my own 22.01 system I see wired use increase but that's not necessarily a problem. The is no need for the kernel to release RAM until the available free ram becomes too low for the requests using it.

Steve

[fireodo]

@Techniker_ctr
@stephenw10 said in Continuously increasing memory usage since the update to 2.6:

On my own 22.01 system I see wired use increase but that's not necessarily a problem. The is no need for the kernel to release RAM until the available free ram becomes too low for the requests using it.

Is it possible that this is a discussion of an old missunderstanding of memory usage in unix systems?

[stephenw10]

Well kinda. But also what changed between 2.5.2 and 2.6.0 to cause the differing usage pattern. And is it a problem.

[Techniker_ctr]

@stephenw10

Hey Steve thanks for your help,

here are the requested pfSense monitoring pages:

Here in a 3 month view:
login-to-view

The Day we applied the update is graphically very well visible.

Here in a 1 day view:
login-to-view

We also had our first outage today which was clearly due to the increased RAM levels:

May  6 08:31:54 xxxx:xxxx:xxxx:xxxx::xxxx 1 2022-05-06T08:31:54.435677+02:00 xxxxxxx.xxxxxxxxx.xx kernel - - - pid 7306 (unbound), jid 0, uid 59, was killed: out of swap space 

Because of the error the systems behind the pfSense were without DNS resolution. Therefore it seems that the RAM is not released for new processes. The system is currently at 94% RAM usage according to our monitoring.

Any Suggestion?

[stephenw10]

Not immediately. Let me see what I can find...

It's interesting that you have not exhausted free memory and the system appears to be releasing inactive memory once free hits 10% which is what I expect.

[Techniker_ctr]

@stephenw10

a small addendum:

we just had a second system with the same failure.

<3>1 2022-05-06T14:57:46.424812+02:00 xxxxxx.xxxxxxxx.xx kernel - - - pid 52014 (unbound), jid 0, uid 59, was killed: out of swap space

Here is the output of the monitoring:
login-to-view

This is a fairly new system uptime 50 days. 03/17 was the deploy so the Data is a bit messy that day.

A rough pattern seems to be slowly emerging:
I am currently monitoring 11 (2.6) systems, following is the uptime along with RAM usage:

VM1: 43 Days 90% (no failure yet)
VM2: 44 Days 90% (no failure yet)
VM3: 01 Days 26% (2GB RAM Testsystem)
VM4: 34 Days 94% (no failure yet)
VM5: 50 Days 93% (first failure)
VM6: 50 Days 93% (second failure)
VM7: 20 Days 61%
VM8: 22 Days 66%
VM9: 22 Days 65%
VM10: 25 days 68%
VM11: 43 Days 89%

VM4 stands out a bit, but there is also a bit more going on than with the others, but it seems that at 50 days the critical mass is reached.

Maybe this information will help with your investigations, if you need more information just ask.

[stephenw10]

And they are all configured the same; 1G RAM, VMs in Hyper-V?

Same package loads?

[Techniker_ctr]

@stephenw10

yes that is correct. Some have 1 or 2 IPsec-Tunnels or ovpn setups. But the fundation is the same

2 Core CPU
1 GB RAM
5 GB SSD
Filesystem: ufs
HV: Hyper-V

Installed Packages:
Cron 0.3.7_5
openvpn-client-export 1.6_4
sudo 0.3_6
Telegraf net-0.9_6

except VM3, which is a new test system with 2 GB RAM

[Techniker_ctr]

@stephenw10

We just had another failure on VM1 due to the RAM usage:

There were error(s) loading the rules: /tmp/rules.debug:19: cannot define table bogonsv6: Cannot allocate memory - The line in question reads [19]: table <bogonsv6> persist file "/etc/bogonsv6"
@ 2022-05-10 16:06:25

login-to-view

[kprovost]

Can you post the output of vmstat -z, ideally on a machine that's using most of its memory? If there's a memory leak in the kernel there may be some indication of it there.