Redis Server Memory Issue

Since adding a 3rd organization to my application, my Redis server has been running out of memory.

In the logs:

 chirpstack-network-server[21311]: time="2021-12-02T20:49:46Z" level=error msg="gateway/mqtt: acquire lock error" error="acquire lock error: MISCONF Redis is configured to save RDB snapshots, but it is currently not able to persist on disk. Commands that may modify the data set are disabled, because this instance is configured to report errors during writes if RDB snapshotting fails (stop-writes-on-bgsave-error option). Please check the Redis logs for details about the RDB error."

Clearly there is some kind of memory issue, so I checked the Redis Log and found a flood of:

14822:M 02 Dec 20:41:15.081 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:15.081 # Can't save in background: fork: Cannot allocate memory

I had the restart Redis in order to fix things, but it is only helping temporarily.

I’m a Redis noob - can anyone help me figure out what could be causing this memory problem?

I tried checking my memory usage and found this:

top - 21:01:07 up 540 days,  5:41,  2 users,  load average: 0.11, 0.16, 0.17
Tasks: 105 total,   2 running,  65 sleeping,   0 stopped,   0 zombie
%Cpu(s): 56.0 us,  4.4 sy,  0.0 ni, 38.3 id,  1.3 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  1008848 total,    62400 free,   493780 used,   452668 buff/cache
KiB Swap:        0 total,        0 free,        0 used.   228980 avail Mem 

Looks like plenty of memory available.

My Full Redis Log:

14822:M 02 Dec 20:35:44.044 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:35:44.044 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:35:50.058 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:35:50.062 * Background saving started by pid 15820
15820:C 02 Dec 20:35:51.668 * DB saved on disk
15820:C 02 Dec 20:35:51.677 * RDB: 2 MB of memory used by copy-on-write
14822:M 02 Dec 20:35:51.764 * Background saving terminated with success
14822:M 02 Dec 20:37:16.033 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:37:16.038 * Background saving started by pid 15867
15867:C 02 Dec 20:37:17.678 * DB saved on disk
15867:C 02 Dec 20:37:17.684 * RDB: 1 MB of memory used by copy-on-write
14822:M 02 Dec 20:37:17.741 * Background saving terminated with success
14822:M 02 Dec 20:38:44.621 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:38:44.621 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:38:50.039 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:38:50.044 * Background saving started by pid 15904
15904:C 02 Dec 20:38:51.620 * DB saved on disk
15904:C 02 Dec 20:38:51.626 * RDB: 1 MB of memory used by copy-on-write
14822:M 02 Dec 20:38:51.649 * Background saving terminated with success
14822:M 02 Dec 20:40:21.942 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:21.943 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:27.056 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:27.056 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:33.071 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:33.071 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:39.088 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:39.089 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:45.004 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:45.005 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:51.023 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:51.023 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:40:57.040 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:40:57.040 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:03.053 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:03.053 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:09.066 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:09.066 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:15.081 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:15.081 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:21.102 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:21.102 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:27.017 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:27.017 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:33.032 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:33.032 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:39.047 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:39.047 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:45.060 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:45.061 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:51.076 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:51.076 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:41:57.088 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:41:57.088 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:42:03.006 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:42:03.006 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:42:09.019 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:42:09.019 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:42:15.035 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:42:15.035 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:42:21.049 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:42:21.050 # Can't save in background: fork: Cannot allocate memory
14822:M 02 Dec 20:42:27.062 * 10000 changes in 60 seconds. Saving...
14822:M 02 Dec 20:42:27.068 * Background saving started by pid 16014
16014:C 02 Dec 20:42:28.665 * DB saved on disk
16014:C 02 Dec 20:42:28.670 * RDB: 2 MB of memory used by copy-on-write
14822:M 02 Dec 20:42:28.774 * Background saving terminated with success
14822:signal-handler (1638477837) 14822:signal-handler (1638477837) Received SIGTERM scheduling shutdown...
Received SIGTERM scheduling shutdown...
14822:M 02 Dec 20:43:57.780 # User requested shutdown...
14822:M 02 Dec 20:43:57.780 * Saving the final RDB snapshot before exiting.
14822:M 02 Dec 20:43:59.293 * DB saved on disk
14822:M 02 Dec 20:43:59.293 * Removing the pid file.
14822:M 02 Dec 20:43:59.294 # Redis is now ready to exit, bye bye...
16044:C 02 Dec 20:43:59.362 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
16044:C 02 Dec 20:43:59.362 # Redis version=4.0.9, bits=64, commit=00000000, modified=0, pid=16044, just started
16044:C 02 Dec 20:43:59.362 # Configuration loaded
                _._                                                  
           _.-``__ ''-._                                             
      _.-``    `.  `_.  ''-._           Redis 4.0.9 (00000000/0) 64 bit
  .-`` .-```.  ```\/    _.,_ ''-._                                   
 (    '      ,       .-`  | `,    )     Running in standalone mode
 |`-._`-...-` __...-.``-._|'` _.-'|     Port: 6379
 |    `-._   `._    /     _.-'    |     PID: 16058
  `-._    `-._  `-./  _.-'    _.-'                                   
 |`-._`-._    `-.__.-'    _.-'_.-'|                                  
 |    `-._`-._        _.-'_.-'    |           http://redis.io        
  `-._    `-._`-.__.-'_.-'    _.-'                                   
 |`-._`-._    `-.__.-'    _.-'_.-'|                                  
 |    `-._`-._        _.-'_.-'    |                                  
  `-._    `-._`-.__.-'_.-'    _.-'                                   
      `-._    `-.__.-'    _.-'                                       
          `-._        _.-'                                           
              `-.__.-'                                               

16058:M 02 Dec 20:43:59.366 # WARNING: The TCP backlog setting of 511 cannot be enforced because /proc/sys/net/core/somaxconn is set to the lower value of 128.
16058:M 02 Dec 20:43:59.366 # Server initialized
16058:M 02 Dec 20:43:59.366 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
16058:M 02 Dec 20:43:59.366 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo never > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled.
16058:M 02 Dec 20:44:00.926 * DB loaded from disk: 1.560 seconds
16058:M 02 Dec 20:44:00.926 * Ready to accept connections

On the assumption that ‘you’re not the first person to encounter this error’, doing a quick search of www shows a number of potential things to check:
THIS, THIS, or ESPECIALLY THIS.

You should learn to help yourself…

Hey @fmgst thanks for the response!

While I didn’t find the same links as you (perhaps you are a better googler than me :slight_smile: ) I did find similar posts suggesting config set stop-writes-on-bgsave-error no. However it seemed like that doesn’t actually solve the problem, just stops it from causing a crash. Is my understanding correct?

Your third link also suggested setting vm.overcommit_memory=1. This seems more promising, but I’m worried about doing it since it isn’t part of the default Chirpstack setup for Redis (and therefore, is presumably not necessary). @brocaar - is this change to overcommit_memory recommended?