OutOfMemoryError in syslog without crash

Setup, Configuration and Use Runtime
1
  • Platform information:
    • Hardware: Linux 64 /16gb ram /100 gb storage not full
    • OS: Debian 10
    • Java Runtime Environment: openjdk 11
    • openHAB version: 3.1.0

Hello everyone,
I see in my /var/log/syslog (and only in syslog, nothing in openhab.log) regular OutOfMemoryError :

Exception in thread “OH-items-40” java.lang.OutOfMemoryError: Java heap space

Always from an OH-items-* thread (but not the same number)
Sometimes with regularity (every 30 seconds, or with one minute between), and sometimes not (2 ou 3 secondes in between, or nothing during several minutes)

The strange part is that the application is working fine. Perfectly responsive. No glitch, no complain at all, everything working as expected.

I have 16g of RAM. Java, by default, allocate approximately 25% of this, so I see 4g allocated with the top command. I have plenty of free ram (I can see it with the command “free” ).
I tried setting the EXTRA_JAVA_OPTS to “-Xmx1g” in the the /etc/default/openhab file. The top command shows that everything is allocated correctly. The application is still working flawlessly.

I made a heapdump with jmap. The heap dump size is only 230 mb
I opened the heap dump file with Eclipse Memory Analyzer and saw absolutely nothing. I have a little warning about a PyDictionary (the biggest object type in memory) which take a staggering size of … 16mb.
How could I have OutOfMemoryError with so little memory effectively used ?? A supposition : one piece of code try to allocate a gigantic object, and the JVM tells it to go away, shut the thread, and throw a OutOfMemoryError in the logs, but the rest of the application is still fine with plenty of free memory ? What do you think ?

I have no error in the openhab log (just one during the hue emulation service initialization, about some cxf interceptor) :

Interceptor for {http://192.168.0.1:80/description.xml}WebClient has thrown exception, unwinding now
org.apache.cxf.interceptor.Fault: Could not send Message.
(I think it’s a false flag)

I tried disabling some bindings of my system, but to no avail. Before spending plenty of time on it,and risking the peace of my system, I wanted to check if someone maybe has an idea ?

2

Post the output of shell:info in the karaf console.

3

Last saturday, I spend several hours trying to get rid of this exception, restart, reboot, etc. To no avail.

But yesterday and today, there is absolutely no trace of another OutOfMemoryError.
I am divided between relief and exasperation.

Thanks for your response, I now know what to do to get/give more information if the issue comes back.
In the meantime, I will monitor it closely.

4

If you have openhab 3.2m3 you can graph the heap used % with the system info binding. Older openhabs do not have the ability.

The heap should not grow in size continuously, it should grow and shrink back to a similar size.

It can be caused by a rule, so if it’s a rare occurrence try using the pause buttons to stop rules and bindings from running temporarily as a test.

2 Likes
5

Excellent, I will do, this will be usefull. Thanks.

6

Hello,

(First of all, for information, since the open post, I upgraded to openhab 3.2)

It’s happening again.
But this time, I found the culprit (mapdb persistence), but not the fix.

I found that the first time the error happen (and only the first), there is a full stack trace :

févr. 09 00:11:09 cellier-serveur karaf[9684]: Exception in thread "OH-items-4" java.lang.OutOfMemoryError: Java heap space
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at java.base/java.util.Arrays.copyOf(Arrays.java:3745)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.StoreDirect.get2(StoreDirect.java:472)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.StoreWAL.get2(StoreWAL.java:336)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.StoreWAL.get(StoreWAL.java:320)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.Caches$HashTable.get(Caches.java:246)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.EngineWrapper.get(EngineWrapper.java:58)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.BTreeMap.put2(BTreeMap.java:677)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.mapdb.BTreeMap.put(BTreeMap.java:643)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.openhab.persistence.mapdb.internal.MapDbPersistenceService.store(MapDbPersistenceService.java:186)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.openhab.core.persistence.internal.PersistenceManagerImpl.handleStateEvent(PersistenceManagerImpl.java:152)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.openhab.core.persistence.internal.PersistenceManagerImpl.stateChanged(PersistenceManagerImpl.java:473)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.openhab.core.items.GenericItem.lambda$1(GenericItem.java:259)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at org.openhab.core.items.GenericItem$$Lambda$1065/0x00000007c136cc40.run(Unknown Source)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
févr. 09 00:11:09 cellier-serveur karaf[9684]:         at java.base/java.lang.Thread.run(Thread.java:829)

It points to this method and the map.put line :

    public void store(Item item, @Nullable String alias) {
        if (item.getState() instanceof UnDefType) {
            return;
        }

        // PersistenceManager passes SimpleItemConfiguration.alias which can be null
        String localAlias = alias == null ? item.getName() : alias;
        logger.debug("store called for {}", localAlias);

        State state = item.getState();
        MapDbItem mItem = new MapDbItem();
        mItem.setName(localAlias);
        mItem.setState(state);
        mItem.setTimestamp(new Date());
        String json = serialize(mItem);
        **map.put(localAlias, json);**
        commit();
        if (logger.isDebugEnabled()) {
            logger.debug("Stored '{}' with state '{}' as '{}' in MapDB database", localAlias, state, json);
        }
    }

So, I set the log level for this class and found out that it happens for every item, on every change. Every attempt to put something in the mapdb map result in a OutOfMemoryError.

my mapdb.persist file is rather simple :

Strategies {
}

Items {
   *: strategy = everyChange
}

The mapdb code is very complex. I only see, thanks to the stack trace, that it falls in an infinite loop, doubling a buffer at each iteration until OutOfMemory occurs.

I don’t know what to do now, other than disabling mapdb.
Is the mapdb database corrupted ? If so, does someone know how I can delete it ?)

7

I should have searched before posting, it wasn’t so hard.
The mapdb is stored in /var/lib/openhab/persistence/mapdb/

I just stopped, deleted everything in this directory, restarted, and it seems to work now.

8

Caution, that the discoverer of lack of memory may not be the thief.

Out of interest, do you have any “exotic” Item types like Location or Call types? There can’t be much unusual about running Mapdb otherwise.

9

Nope, don’t know this item types.
My guess is that the mapdb database was corrupted, as its deletion seems to have fix the issue.
I could ask, how was this corrupted ?
Maybe a wild reboot occuring with a power failure ? Or when I got my file system full ?
Don’t know, but now it’s working…
…
Until next time :sweat_smile: