High memory usage in OH 2.5.3

Hi,
today I upgraded to OH2.5.3 as previous 2.5.2 wasn’t stable due to high memory consumption.
I decided to open this thread as even though problem with growing memory was observed before in different releases, it was either solved or not related to the recent software. I think new thread will present clean view on it.

I’m running OH on the RPi 3 and there isn’t much deployed apart from OH there.
It was rock solid stable until 2.4.x and then after 2.5.2 upgrade it started causing issues (I think even 2.5.1 was OK but as I’m not 100% sure I don’t want to mess around). Currently, even after restarts for some reason memory is growing to the following levels:

pi@dom-pi:/usr/share/openhab2/misc $ top
top - 10:36:23 up 28 min,  1 user,  load average: 0.18, 0.53, 1.34
Tasks: 116 total,   1 running, 115 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.9 us,  1.1 sy,  0.0 ni, 96.8 id,  0.2 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :    926.1 total,     35.0 free,    421.3 used,    469.7 buff/cache
MiB Swap:    100.0 total,     98.7 free,      1.2 used.    437.9 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  585 openhab   20   0  586712 309372  15216 S   5.9  32.6   6:33.27 java

and floats between 35-50MB free causing system to be hardly responsive. Sometimes there is a peak in the usage causing that CLI freezes for simple commands.
Is there anything I can improve in the configuration here or rather this is SW issue in the latest release?

What other services are you running on your pi? Openhab uses only 310mb of memory, so something else must be using a lot more of it.

Since just addons were updated one of your addons may be causing the issue. Try clear cache first.

I cleaned the cache. It doesn’t help.

  1. When OH stops the free memory is about 450MB, the rest is distributed across used and buff/cache.
  2. Then during OH startup I observed in ‘top’ the memory change in the following way:
    it starts quickly growing the buff/cache to 500-600M, not increasing used that much (from ~100MB to ~270MB), then cache/buff drops to about 480M and used grows up to 405MB, leaving free at the level of ~35-37MB. In that case startup takes veery long (10min or so).

It doesn’t change in mid-term, maybe after hours it would differ but I doubt.
I don’t know why cache/buff grows that much.

The full list from ‘top’ below:

top - 11:58:48 up  1:50,  2 users,  load average: 3.01, 3.96, 2.92
Tasks: 128 total,   1 running, 127 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.8 us,  1.3 sy,  0.0 ni, 96.9 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
MiB Mem :    926.1 total,     36.6 free,    403.5 used,    486.0 buff/cache
MiB Swap:    100.0 total,     95.7 free,      4.2 used.    455.1 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
24631 openhab   20   0  535876 283980  13916 S   7.2  29.9   4:23.73 java
30444 pi        20   0   10588   3092   2560 R   1.0   0.3   0:00.12 top
28578 pi        20   0    7584   2524   2380 S   0.7   0.3   0:01.42 bash
  328 pi        20   0   57776  24864   8168 S   0.3   2.6   0:51.05 pywws-livelog
  752 mysql     20   0  610676  57848  15432 S   0.3   6.1   0:08.88 mysqld
21290 root      20   0       0      0      0 I   0.3   0.0   0:01.23 kworker/u8:1-events_unbound
23365 pi        20   0   12972   5796   4816 S   0.3   0.6   0:06.14 sshd
    1 root      20   0   33652   7732   6400 S   0.0   0.8   0:04.78 systemd
    2 root      20   0       0      0      0 S   0.0   0.0   0:00.01 kthreadd
    3 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_gp
    4 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rcu_par_gp
    8 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 mm_percpu_wq
    9 root      20   0       0      0      0 S   0.0   0.0   0:00.39 ksoftirqd/0
   10 root      20   0       0      0      0 I   0.0   0.0   0:03.52 rcu_sched
   11 root      20   0       0      0      0 I   0.0   0.0   0:00.00 rcu_bh
   12 root      rt   0       0      0      0 S   0.0   0.0   0:00.07 migration/0
   13 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/0
   14 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/1
   15 root      rt   0       0      0      0 S   0.0   0.0   0:00.06 migration/1
   16 root      20   0       0      0      0 S   0.0   0.0   0:00.11 ksoftirqd/1
   19 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/2
   20 root      rt   0       0      0      0 S   0.0   0.0   0:00.01 migration/2
   21 root      20   0       0      0      0 S   0.0   0.0   0:00.24 ksoftirqd/2
   24 root      20   0       0      0      0 S   0.0   0.0   0:00.00 cpuhp/3
   25 root      rt   0       0      0      0 S   0.0   0.0   0:00.06 migration/3
   26 root      20   0       0      0      0 S   0.0   0.0   0:00.06 ksoftirqd/3
   28 root       0 -20       0      0      0 I   0.0   0.0   0:00.78 kworker/3:0H-kblockd
   29 root      20   0       0      0      0 S   0.0   0.0   0:00.00 kdevtmpfs
   30 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 netns
   34 root      20   0       0      0      0 S   0.0   0.0   0:00.01 khungtaskd
   35 root      20   0       0      0      0 S   0.0   0.0   0:00.00 oom_reaper
   36 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 writeback
   37 root      20   0       0      0      0 S   0.0   0.0   0:00.00 kcompactd0
   38 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 crypto
   39 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 kblockd
   40 root      rt   0       0      0      0 S   0.0   0.0   0:00.00 watchdogd
   42 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 rpciod
   43 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 kworker/u9:0
   44 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 xprtiod
   47 root      20   0       0      0      0 S   0.0   0.0   0:01.03 kswapd0
   48 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 nfsiod
   59 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 kthrotld
   60 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 iscsi_eh
   61 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 dwc_otg
   62 root       0 -20       0      0      0 I   0.0   0.0   0:00.00 DWC Notificatio
   63 root       1 -19       0      0      0 S   0.0   0.0   0:00.00 vchiq-slot/0
   64 root       1 -19       0      0      0 S   0.0   0.0   0:00.00 vchiq-recy/0
   65 root       0 -20       0      0      0 S   0.0   0.0   0:00.00 vchiq-sync/0
   66 root      20   0       0      0      0 S   0.0   0.0   0:00.00 vchiq-keep/0
   67 root      10 -10       0      0      0 S   0.0   0.0   0:00.00 SMIO
   69 root     -51   0       0      0      0 S   0.0   0.0   0:00.02 irq/86-mmc1

I don’t have statistics from before the upgrade but I didn’t have any issues with memory, I had very safe margin.

When I was regularly using my Pi 3B+ with just expire & zwave bindings, it took about 512mb.

in my case it is related to version upgrade, not knowing what exactly causes it.
I’d like obviously understand which component is causing it to remove/disable as in long term (about 1 week) it is causing OH crash due to low memory.
How can I check consumption per add-on?

I don’t see anything unusual about your memory usage.
It’s even a pretty small instance actually. Larger setups consume more (like mine to use ~750MB with ~550MB resident, also on Pi3).
Don’t stare at the ‘free’ value, it is actually meaningless as the OS uses all but a defined minimum of the available capacity for caching but will release that immediately whenever any app requests memory.

As you say you encounter freezes, find out first if that’s due to memory. Run iostat 2 or the like to see if the system starts paging when it gets slow. It could well be due to other reasons such as SD corruption.

You didn tell us your OS specs, please follow How to ask a good question / Help Us Help You - Tutorials & Examples - openHAB Community next time you post.

Do you use openHABian ? If no move over there and enable ZRAM, that’s a memory optimized setup.

Get the openhab java process ID (using ps). Then run the following (replacing process-id with the openhab java process id. This will report memory usage every 5 seconds. If something in openHAB is leaking memory, you’ll see evidence of it here.

pidstat -r -p process-id 5

Note if pidstat is not found, you may need to install the sysstat package.

Exactly. So misleading. It’s always best to look specifically at the suspect process to see what it’s consuming (as I describe above).

Also a very good idea. I think you also need the sysstat package for this utility.

Hi Guys,
thanks for your efforts above. Sorry for not telling the OS, completely missed it. I’m on Raspbian Buster.
My output (IMHO 30% by OH now is a lot more than used to be, but as said I don’t have stats from before upgrade and didn’t check it when there was no noticeable problem):

pi@dom-pi:~ $ ps -ef | grep openhab
pi       17744 15916  0 13:25 pts/0    00:00:00 grep --color=auto openhab
openhab  24631     1 11 11:42 ?        00:11:45 /usr/bin/java -Dopenhab.home=/usr/share/openhab2 -Dopenhab.conf=/etc/openhab2 -Dopenhab.runtime=/usr/share/openhab2/runtime -Dopenhab.userdata=/var/lib/openhab2 -Dopenhab.logdir=/var/log/openhab2 -Dfelix.cm.dir=/var/lib/openhab2/config -Djava.library.path=/var/lib/openhab2/tmp/lib -Djetty.host=0.0.0.0 -Djetty.http.compliance=RFC2616 -Dorg.ops4j.pax.web.listening.addresses=0.0.0.0 -Dorg.osgi.service.http.port=8080 -Dorg.osgi.service.http.port.secure=8443 -Djava.awt.headless=true -Duser.country=PL -Duser.language=pl -Djava.endorsed.dirs=/usr/lib/jvm/java-8-oracle/jre/jre/lib/endorsed:/usr/lib/jvm/java-8-oracle/jre/lib/endorsed:/usr/share/openhab2/runtime/lib/endorsed -Djava.ext.dirs=/usr/lib/jvm/java-8-oracle/jre/jre/lib/ext:/usr/lib/jvm/java-8-oracle/jre/lib/ext:/usr/share/openhab2/runtime/lib/ext -Dkaraf.instances=/var/lib/openhab2/tmp/instances -Dkaraf.home=/usr/share/openhab2/runtime -Dkaraf.base=/var/lib/openhab2 -Dkaraf.data=/var/lib/openhab2 -Dkaraf.etc=/var/lib/openhab2/etc -Dkaraf.log=/var/log/openhab2 -Dkaraf.restart.jvm.supported=true -Djava.io.tmpdir=/var/lib/openhab2/tmp -Djava.util.logging.config.file=/var/lib/openhab2/etc/java.util.logging.properties -Dkaraf.startLocalConsole=false -Dkaraf.startRemoteShell=true -classpath /usr/share/openhab2/runtime/lib/boot/org.apache.karaf.diagnostic.boot-4.2.7.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.jaas.boot-4.2.7.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.main-4.2.7.jar:/usr/share/openhab2/runtime/lib/boot/org.apache.karaf.specs.activator-4.2.7.jar:/usr/share/openhab2/runtime/lib/boot/osgi.core-6.0.0.jar org.apache.karaf.main.Main
pi@dom-pi:~ $ pidstat -r -p 24631 5
Linux 4.19.97-v7+ (dom-pi)      03/20/2020      _armv7l_        (4 CPU)

01:26:05 PM   UID       PID  minflt/s  majflt/s     VSZ     RSS   %MEM  Command
01:26:10 PM   109     24631      4.40      0.00  542352  288496  30.42  java
01:26:15 PM   109     24631      0.80      0.00  542352  288496  30.42  java
01:26:20 PM   109     24631      1.00      0.00  542352  288496  30.42  java
01:26:25 PM   109     24631      0.80      0.00  542352  288496  30.42  java
01:26:30 PM   109     24631      0.00      0.00  542352  288496  30.42  java
01:26:35 PM   109     24631      0.20      0.00  542352  288496  30.42  java
01:26:40 PM   109     24631      0.00      0.00  542352  288496  30.42  java
01:26:45 PM   109     24631      2.20      0.00  542352  288496  30.42  java
^C
Average:      109     24631      1.17      0.00  542352  288496  30.42  java
pi@dom-pi:~ $ iostat 2
Linux 4.19.97-v7+ (dom-pi)      03/20/2020      _armv7l_        (4 CPU)

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           3.08    0.00    0.96    7.62    0.00   88.34

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           3.06        68.51        64.58     816906     770013
sda               0.01         0.26         0.00       3092          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.40    0.00    0.51    0.00    0.00   98.09

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           0.00         0.00         0.00          0          0
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.77    0.00    1.27    0.00    0.00   96.96

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           0.00         0.00         0.00          0          0
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.39    0.00    1.14    0.25    0.00   97.22

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           1.50         0.00        10.00          0         20
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           0.77    0.00    0.77    0.00    0.00   98.47

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           0.50         0.00         8.00          0         16
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.65    0.00    0.76    0.00    0.00   97.59

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           0.00         0.00         0.00          0          0
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           1.89    0.00    1.26    0.00    0.00   96.84

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           0.00         0.00         0.00          0          0
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           2.04    0.00    1.15    0.13    0.00   96.69

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
mmcblk0           1.00         0.00         6.00          0         12
sda               0.00         0.00         0.00          0          0

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           2.03    0.00    1.27    0.00    0.00   96.70

I’ve just noticed that about 1-1.5h after restart it got to the level:

top - 13:30:51 up  3:22,  1 user,  load average: 0.62, 0.59, 0.37
Tasks: 122 total,   1 running, 121 sleeping,   0 stopped,   0 zombie
%Cpu(s):  1.3 us,  1.4 sy,  0.0 ni, 97.1 id,  0.1 wa,  0.0 hi,  0.1 si,  0.0 st
MiB Mem :    926.1 total,    200.3 free,    407.1 used,    318.7 buff/cache
MiB Swap:    100.0 total,     94.2 free,      5.8 used.    452.0 avail Mem

which looks different than before (I understood your point about not looking religiously at ‘free’). It took it decent time to get to this point though. responsivness is much better, maybe it was some temporary and incidental issue just after the upgrade. Waiting to see your comments whether you think I should worry about 30% mem usage by java and maybe this deserves closing…

This doesn’t strike as unusual at all.

If it stays close to 30.4 after running pidstat for a couple hours, you likely can conclude that openHAB is not leaking memory.

The one thing I know causes OH to leak memory is an invalid binding in addons.cfg or addons.config. You would see evidence of that in pidstat by a blip in page faults (minflt) along with a slight increase in RSS and %MEM every minute.

1 Like

thanks @mhilbush, I will keep observing, for the moment it doesn’t leak. Apparently there was a spike in usage after upgrade (I don’t know exact mechanisms of OH but it was like creating some cache or updating some other data by the new SW) which got flatten after some period of time. Thanks everyone involved for your hints!

1 Like

@mhilbush, can the below be indication of a leak or too little changes:

Linux 4.19.97-v7+ (dom-pi)      03/20/2020      _armv7l_        (4 CPU)

03:18:44 PM   UID       PID  minflt/s  majflt/s     VSZ     RSS   %MEM  Command
03:18:49 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:18:54 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:18:59 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:19:04 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:19:09 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:19:14 PM   109     24631      1.00      0.00  542160  289336  30.51  java
03:19:19 PM   109     24631      0.00      0.00  542160  289336  30.51  java
03:19:24 PM   109     24631      0.60      0.00  542160  289336  30.51  java
03:19:29 PM   109     24631      0.20      0.00  542160  289336  30.51  java
03:19:34 PM   109     24631      0.00      0.00  542160  289336  30.51  java
^C
Average:      109     24631      0.18      0.00  542160  289336  30.51  java

very little growth but noticeable on the memory and RSS

That looks pretty normal.

Here’s an example of what a leak looks like.

04:25:45 PM     0     12299      1.17      0.00 6992176  938964  11.49  java
04:25:51 PM     0     12299      0.33      0.00 6992176  938964  11.49  java
04:25:57 PM     0     12299      0.33      0.00 6992176  938964  11.49  java
04:26:03 PM     0     12299      0.83      0.00 6992176  938964  11.49  java
04:26:09 PM     0     12299      0.67      0.00 6992176  938964  11.49  java
04:26:15 PM     0     12299      0.17      0.00 6992176  938964  11.49  java
04:26:21 PM     0     12299      0.33      0.00 6992176  938964  11.49  java
04:26:27 PM     0     12299     10.00      0.00 6992176  938964  11.49  java
04:26:33 PM     0     12299    349.17      0.00 6994224  945720  11.57  java
04:26:39 PM     0     12299     21.67      0.00 6994224  945804  11.57  java
04:26:45 PM     0     12299      0.33      0.00 6994224  945804  11.57  java
04:26:51 PM     0     12299      0.50      0.00 6994224  945804  11.57  java
04:26:57 PM     0     12299      3.67      0.00 6994224  945804  11.57  java
04:27:03 PM     0     12299      0.33      0.00 6994224  945804  11.57  java
04:27:09 PM     0     12299      0.17      0.00 6994224  945804  11.57  java
04:27:15 PM     0     12299      0.00      0.00 6994224  945804  11.57  java
04:27:21 PM     0     12299      0.67      0.00 6994224  945804  11.57  java
04:27:27 PM     0     12299    469.00      0.00 6994224  956616  11.70  java
04:27:33 PM     0     12299    196.83      0.00 6994224  959980  11.74  java
04:27:39 PM     0     12299      4.17      0.00 6994224  959836  11.74  java
04:27:45 PM     0     12299      0.67      0.00 6994224  959836  11.74  java
04:27:51 PM     0     12299      0.33      0.00 6994224  959836  11.74  java
04:27:57 PM     0     12299      0.00      0.00 6994224  959836  11.74  java
04:28:03 PM     0     12299      1.17      0.00 6994224  959836  11.74  java
04:28:09 PM     0     12299      0.50      0.00 6994224  959836  11.74  java
04:28:15 PM     0     12299      0.17      0.00 6994224  959836  11.74  java
04:28:21 PM     0     12299      0.50      0.00 6994224  959836  11.74  java
04:28:27 PM     0     12299     11.17      0.00 6994224  959908  11.74  java
04:28:33 PM     0     12299    524.50      0.00 6994224  970840  11.88  java
04:28:39 PM     0     12299      5.17      0.00 6994224  970840  11.88  java
04:28:45 PM     0     12299     10.17      0.00 6994224  970840  11.88  java
04:28:51 PM     0     12299      0.50      0.00 6994224  970840  11.88  java
04:28:57 PM     0     12299      0.00      0.00 6994224  970840  11.88  java

For me the Pi 3B+ was not enough in terms of hardware as I ran other (heavier) tasks on it next to openHAB.
However I also think that your Mem usage is not that bad, maybe other things can cause this freezing (which is not strongly related to the size of the memory).
Also as others said:

  • I think all operating systems will use the (or it will be seen like this) most of the memory to run everything as smoothly as it can. I think you can experience same behavior on a client. Like my computer has 16GB RAM, and after just turning on it will use 8-9 GB, while Windows can also run with 2-4 GB…
  • openHAB memory usage will always keep climbing until the predefined max memory usage. This is because in languages like Java, not used values and objects (hopes it makes sense to you) will be only cleaned if it is out of memory, so not instantly…

Thanks guys for your efforts
Edit, after 2 days: memory seems to be quite stable so there wasn’t a real problem. Issue was apparently after version change where OH slowed down significantly but then recovered.