[Bug] GT-AX6000 - swappiness=0 causing issues when swap is needed

[ColinTaylor]

Tested - Found True

What is true exactly? The issue being reported was that swapping didn't take place on a GT-AX6000 with swappiness=0. Are you saying that's not the case?

 

[Weblee2407]

What is true exactly? The issue being reported was that swapping didn't take place on a GT-AX6000 with swappiness=0. Are you saying that's not the case?

Not at all. My swappiness value is 72. I was noting that what Martinski said about when swapping would start was accurate.

I will set it to 0 and reboot and disable scheduled reboot and post what happens when it gets to this same level.

 

[Weblee2407]

Set swappiness to 0 and disabled scheduled reboot to force memory exhaustion. I also wrote a script to check mem in use % and post the swapping count. With 96.65 % in use, swap count is still 0 (check code in log extract)

Aug 30 15:46:55 Irongate evtmon: - SwapMon: Utilization 85.70% with Status check code 0
Aug 30 15:51:12 Irongate evtmon: - SwapMon: Utilization 85.75% with Status check code 0
Aug 30 15:53:51 Irongate evtmon: - SwapMon: Utilization 85.78% with Status check code 0
Aug 30 16:00:00 Irongate evtmon: - SwapMon: Utilization 85.80% with Status check code 0
Aug 30 16:15:00 Irongate evtmon: - SwapMon: Utilization 85.85% with Status check code 0
Aug 30 16:30:00 Irongate evtmon: - SwapMon: Utilization 85.95% with Status check code 0
Aug 30 16:45:00 Irongate evtmon: - SwapMon: Utilization 86.17% with Status check code 0
Aug 30 17:00:00 Irongate evtmon: - SwapMon: Utilization 86.29% with Status check code 0
Aug 30 17:15:00 Irongate evtmon: - SwapMon: Utilization 86.33% with Status check code 0
Aug 30 17:30:00 Irongate evtmon: - SwapMon: Utilization 86.84% with Status check code 0
Aug 30 17:45:00 Irongate evtmon: - SwapMon: Utilization 86.77% with Status check code 0
Aug 30 18:00:00 Irongate evtmon: - SwapMon: Utilization 86.80% with Status check code 0
Aug 30 18:15:00 Irongate evtmon: - SwapMon: Utilization 86.90% with Status check code 0
Aug 30 18:30:00 Irongate evtmon: - SwapMon: Utilization 87.03% with Status check code 0
Aug 30 18:45:00 Irongate evtmon: - SwapMon: Utilization 87.04% with Status check code 0
Aug 30 18:55:43 Irongate evtmon: - SwapMon: Utilization 87.26% with Status check code 0
Aug 30 19:00:00 Irongate evtmon: - SwapMon: Utilization 87.33% with Status check code 0
Aug 30 19:00:06 Irongate evtmon: - SwapMon: Utilization 87.33% with Status check code 0
Aug 30 19:07:14 Irongate evtmon: - SwapMon: Utilization 87.13% with Status check code 0
Aug 30 19:07:24 Irongate evtmon: - SwapMon: Utilization 87.16% with Status check code 0
Aug 30 19:15:00 Irongate evtmon: - SwapMon: Utilization 87.10% with Status check code 0
Aug 30 19:30:00 Irongate evtmon: - SwapMon: Utilization 88.72% with Status check code 0
Aug 30 19:45:00 Irongate evtmon: - SwapMon: Utilization 90.31% with Status check code 0
Aug 30 20:00:00 Irongate evtmon: - SwapMon: Utilization 91.83% with Status check code 0
Aug 30 20:15:00 Irongate evtmon: - SwapMon: Utilization 93.07% with Status check code 0
Aug 30 20:30:00 Irongate evtmon: - SwapMon: Utilization 94.36% with Status check code 0
Aug 30 20:45:00 Irongate evtmon: - SwapMon: Utilization 95.45% with Status check code 0
Aug 30 21:00:00 Irongate evtmon: - SwapMon: Utilization 97.32% with Status check code 0
Aug 30 21:15:00 Irongate evtmon: - SwapMon: Utilization 97.20% with Status check code 0
Aug 30 21:30:00 Irongate evtmon: - SwapMon: Utilization 97.26% with Status check code 0
Aug 30 21:45:00 Irongate evtmon: - SwapMon: Utilization 97.37% with Status check code 0
Aug 30 22:00:00 Irongate evtmon: - SwapMon: Utilization 96.56% with Status check code 0

Free output
total used free shared buffers cached
Mem: 1018848 986556 32292 2396 174912 256680
-/+ buffers/cache: 554964 463884
Swap: 2097148 0 2097148

cat /proc/meminfo output

MemTotal: 1018848 kB
MemFree: 31488 kB
MemAvailable: 413664 kB
Buffers: 174972 kB
Cached: 256720 kB
SwapCached: 0 kB
Active: 392680 kB
Inactive: 171668 kB
Active(anon): 129544 kB
Inactive(anon): 5516 kB
Active(file): 263136 kB
Inactive(file): 166152 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 2097148 kB
SwapFree: 2097148 kB
Dirty: 32 kB
Writeback: 0 kB
AnonPages: 132660 kB
Mapped: 26856 kB
Shmem: 2400 kB
Slab: 160472 kB
SReclaimable: 18416 kB
SUnreclaim: 142056 kB
KernelStack: 2652 kB
PageTables: 2284 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 2606572 kB
Committed_AS: 268340 kB
VmallocTotal: 263061440 kB
VmallocUsed: 0 kB
VmallocChunk: 0 kB
Percpu: 800 kB
CmaTotal: 180224 kB
CmaFree: 4 kB

weblee@irongate:/tmp/home/root# cat /proc/swaps
Filename Type Size Used Priority
/tmp/mnt/SSDv6/myswap.swp file 2097148 0 -2

GT-ax6000 386.7_2
Skynet, Diversion (large), YazDHCP, Scribe,UIScribe,logRotate,one VPN client active, caching dns enabled

I will let it continue to run until full memory exhaustion

 

[sfx2000]

If one doesn't have a swap file, it doesn't matter what the value of swappiness is..

It's a moot point then - stock firmware doesn't have a swap file, so it can be set to whatever

Agent Smith - what good is a phone call if you can't even speak?

 

[ColinTaylor]

If one doesn't have a swap file, it doesn't matter what the value of swappiness is..

It's a moot point then - stock firmware doesn't have a swap file, so it can be set to whatever

So, missed the entire point of this thread then.

 

[Weblee2407]

Still monitoring, but it never reaches 100% memory usage. Uninstalled log rotate (scribe) so maybe I can get a max out soon. I have gotten up to 96% but no swapping.

 

[ColinTaylor]

Thanks for the update.

 

[Martinski]

Still monitoring, but it never reaches 100% memory usage. Uninstalled log rotate (scribe) so maybe I can get a max out soon. I have gotten up to 96% but no swapping.

This is good. It means that, at least up to this point, the built-in memory management is working & handling RAM usage & memory reclamation as it should when it gets close to memory exhaustion.

I suppose it's possible that in newer router models with a "newer" kernel version (4.19.183 vs 4.1.27), the memory management is slightly better so swapping is much less likely to happen when swappiness == 0 (but this is just pure speculation on my part).

Also, keep in mind that when swappiness == 0, the trigger rule is different:

When swappiness value == 0, swapping occurs only when the combined value of file-backed pages (nr_file_pages) and free (nr_free_pages) pages is less than the "high water mark."

Now, *assuming* that the above has *not* been modified for your particular router model, it's rather difficult to predict the percentage of RAM usage at which swapping would be triggered (if at all) because it's not based on only the current number of free pages, but also on the current number of file-backed pages, both of which dynamically change as RAM is allocated & deallocated while the router is operating & performing its tasks.

 

[Weblee2407]

Well I hate to admit it, but I gave up on this test. I was trying to get logging of events when the memory got constrained but couldn't. Seems as if syslog gets hung or stops posting and the router crashes and restarts.

I set my swappiness to 85, and I'm just going to run with it. When the VPN has active connections the usage goes up, and it does start swapping, but it never did with swappiness at 0

 

[SomeWhereOverTheRainBow]

Well I hate to admit it, but I gave up on this test. I was trying to get logging of events when the memory got constrained but couldn't. Seems as if syslog gets hung or stops posting and the router crashes and restarts.

I set my swappiness to 85, and I'm just going to run with it. When the VPN has active connections the usage goes up, and it does start swapping, but it never did with swappiness at 0

85 might lead to a bit too much swapping, you should consider picking a number between 40 to 65. That is assuming you care about your usb's mileage.

 

[Weblee2407]

....ah! never thought of it that way.

 

[ColinTaylor]

Well I hate to admit it, but I gave up on this test. I was trying to get logging of events when the memory got constrained but couldn't. Seems as if syslog gets hung or stops posting and the router crashes and restarts.

Can you clarify at what point you started experiencing the problems? The last time you posted you had been running with swappiness=0 for over a week and hadn't had any problems.

 

[Weblee2407]

Sure - The router got into the 95-97 percent of memory usage, and I was trying to push it to 100. I connected to the 1st VPN server and ran a speed test on the device. The webpage didn't seem to update, and I was trying to see syslog in the GUI. Boom, the router would reboot

So I stopped that type of testing - was going to pick up when I had time to read how to use packet generator. Router rebooted twice 8 hrs apart with last memory usage posting of 96% in use. I did a full reset at that point because I was sure I had corrupted something and the family was giving me grief.

I remembered just today I had set verbosity to 6 when I was having VPN problems from windows clients, and I had never set it back. So I'm pretty sure I was overwhelming syslogd or something.

EDIT: I want to add that there does seem to be some sort of memory leak because usage grows and grows now matter what.

 

[ColinTaylor]

EDIT: I want to add that there does seem to be some sort of memory leak because usage grows and grows now matter what.

You have a USB drive and addons that constantly write to it, e.g. Diversion and Scribe. Therefore it's expected that the memory usage will increase over time to ~97%.

If merely using the VPN connection causes swapping or reboots then I'd say you have a more fundamental problem with the operation of your router. You should be able to see any relevant errors in the Scribe logs - that's the whole purpose of installing Scribe.

 

[Weblee2407]

Well, I won't say "just one more post" because I have a question. I left swappiness at zero and still tracked memory usage....usage went up to 97%. I wake up th today and the memory usage is at 65%, no reboot I am able to determine (uptime still has days) and my WAN event didn't fire. Furthermore, I checked the logs to see when the usage went down, but the last time my monitoring cron job fired was 6pm yesterday (Sept 22).

How can I investigate this?

Is there some type of process that can account for this memory flush and if so, can it be called on demand?

And what does this mean? Possibly idling CPU's and releasing memory of the assigned processes? It is the only abnormal thing I have in the message log.
Sep 23 00:13:13 irongate kernel: NOHZ: local_softirq_pending 202
Sep 23 00:13:13 irongate kernel: NOHZ: local_softirq_pending 202
Sep 23 00:13:13 irongate kernel: NOHZ: local_softirq_pending 202

 

[ColinTaylor]

Is there some type of process that can account for this memory flush ...

Yes there are lots of situations where the memory is flushed. One common one would be a process that creates a large (>500MB) temporary file on disk and then deletes it. You're running multiple addon scripts that could exhibit this sort of behaviour.

 

[Weblee2407]

Well I have no more concern about swapping.

 

[Martinski]

... I left swappiness at zero and still tracked memory usage....usage went up to 97%. I wake up th today and the memory usage is at 65%, no reboot I am able to determine (uptime still has days) and my WAN event didn't fire.

Yes there are lots of situations where the memory is flushed. One common one would be a process that creates a large (>500MB) temporary file on disk and then deletes it. You're running multiple addon scripts that could exhibit this sort of behaviour.

@ColinTaylor has a good point. When the router reaches ~97% RAM usage, it means that the amount of "free RAM" is roughly about 31MB (out of 1GB RAM total). At that low level, even a 100MB memory allocation request would most certainly trigger a large flush of "used RAM" which would essentially reclaim a lot of the "inactive" used memory, marking it as "free" which, in turn, may result in a significant reduction in the percentage of RAM usage.

One key point to understand & keep in mind is that when the router's web GUI reports "x% RAM" utilization & "n MB" of free RAM, those numbers reflect values based on the amount of "free RAM" as reported by "/proc/meminfo" in "MemFree:" and shown on the "Mem:" line from the "free" command output.

But, in reality, there is normally much more RAM available for the OS to use than what is reported as "free" by the router's GUI. The more meaningful values in terms of RAM *availability* are the ones shown in the "-/+ buffers/cache:" line from the "free" command output, and in "MemAvailable:" from "/proc/meminfo"

For example, let's look at the memory status you reported in post #43 (I'll try to keep the explanations brief since going into further details would make this excessively longer).

>> free
          total        used      free   shared   buffers   cached
Mem:    1018848      986556     32292     2396    174912   256680
-/+ buffers/cache:   554964    463884
Swap:   2097148           0   2097148
----------------------------
>> cat /proc/meminfo

MemTotal:        1018848 kB
MemFree:           31488 kB
MemAvailable:     413664 kB
Buffers:          174972 kB
Cached:           256720 kB
SwapCached:            0 kB
Active:           392680 kB
Inactive:         171668 kB
Active(anon):     129544 kB
Inactive(anon):     5516 kB
Active(file):     263136 kB
Inactive(file):   166152 kB
...

From the "Mem:" line in "free" cmd output:
=============================
Total: 1018848 KB ~= 994.97 MB
Total usable RAM as seen by the OS. It's normally less than the total physical RAM because the kernel reserves some memory for itself & for various initial data structures & startup components/modules required for basic operations.

Used_1: 986556 KB ~= 963.43 MB
Amount of RAM currently being "used" by the system, *including* "Buffers" & "Cached" amounts.

Free_1: 32292 KB ~= 31.54 MB
Amount of RAM currently free. This *excludes* "Buffers" & "Cached" amounts.

["Total" - "Used_1"].
[1018848 - 986556] = 32292 KB ~= 31.54 MB

Shared: 2396 KB
Amount of RAM specifically allocated to be used & shared by multiple processes.

Buffers: 174912 KB
Amount of RAM used for temporary storage of raw disk blocks.

Cached: 256680 KB
Amount of RAM used for temporary storage of file contents read from disk.

The data in "Buffers" & "Cached" memory is meant for faster access, avoiding expensive disk I/O operations as much as possible.

From the "-/+ buffers/cache" line in "free" cmd output:
====================================
Used_2: 554964 KB ~= 541.96 MB
Amount of RAM currently being used by the system, *excluding* "Buffers" & "Cached" amounts.

["Used_1" - "Buffers" - "Cached"]
[986556 - 174912 - 256680] = 554964 KB ~= 541.96 MB

Free_2: 463884 KB ~= 453.01 MB
Amount of RAM currently free. This *includes* "Buffers" & "Cached" amounts.

["Total" - "Used_2"].
[1018848 - 554964] = 463884 KB ~= 453.01 MB


As you can see, in this particular example there's a big difference between the amounts shown for "Free_1" RAM (32292 KB ~= 31.54 MB) & "Free_2" RAM (463884 KB ~= 453.01 MB).

The discrepancy is due to the fact that "Buffers" & "Cached" memory, while marked as being "used" by the system, can potentially be freed & made available for new memory allocations when "Free_1" RAM becomes too low to satisfy a request, so they are included when calculating the amount of "Free_2" RAM. And that's why the latter is more meaningful in terms of actual RAM availability.

However, note that not all "Buffers" & "Cached" memory pages are equally available to be freed at any time. There are some factors to be considered such as whether those RAM pages are marked as "Active" or "Inactive." This is why the value in "MemAvailable:" from "/proc/meminfo" tends to be lower than the "Free_2" RAM value but it's a bit more realistic.

The key point is that, under normal circumstances, there is actually much more RAM that can be made readily available to the OS than what the GUI reports as free, especially when memory exhaustion appears very near.

My 2 cents.

 

[bloomwow]

Adding my data point:

GT-AXE11000. Fresh setup with Adguard Home + Skynet + a couple other plugins. Had it run for more than a full day. Went home today only to get no internet connection. Went into router web portal and found out free mem @ less than 30MB + all CPU cores at full usage.

At this stage I could no longer log into adguardhome's web portal. top showed that adguardhome was the main resource hog. I was struggling to open amtm let alone entering menu items.

Did some research and found this thread. The snappiness output turned out to be indeed 0. Set it to 60 and in a few moments everything went back. Checked sysinfo page and ~300MB of swap was in use (doing its job).

Decided to add the line that configures swappiness to boot script just to be safe.

Still trying to find a way to reduce adguards memory footprint without needing to constantly reboot...

So yeah, GT-AXE11000 has snappiness set to 0 by default as well.

 

[Weblee2407]

Wow - 300 mb! My swap starts at about 90% memory usage and allocates about 4mb initially and grows to about 20+- mb over time. On the prior version of Merlin GT-AX6000_386.7_2,
Swapping would start at about 20 mb and the highest I saw was 55 mb.

Maybe a hardware difference, but I wish mine would swap more because the webpage locks up sometimes when I go into logs -especially skynet.