Identifying problematic item (out of Memory / Java heap)

I am running openhabian v1.4.1-416(de039da) on a raspberry pi 3 (OH 2.4 M4)
The problem below is true for 2.3 stable as well:

I get another java heap space error (OOM) 17 minutes after a restart

2018-10-26 07:29:49.207 [INFO ] [.binding.km200.internal.KM200Binding] - ... Update of the KM200 Binding configuration completed
2018-10-26 07:29:49.242 [INFO ] [b.core.service.AbstractActiveService] - KM200 Binding has been started
2018-10-26 07:29:57.830 [INFO ] [] - MQTT Service initialization completed.
2018-10-26 07:29:57.834 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'
2018-10-26 07:29:57.834 [INFO ] [b.core.service.AbstractActiveService] - Denon Refresh Service has been started
2018-10-26 07:30:00.015 [INFO ] [arthome.model.script.moverules.rules] - system started triggered
2018-10-26 07:30:00.260 [INFO ] [arthome.model.script.moverules.rules] - timer created
2018-10-26 07:30:00.278 [INFO ] [marthome.model.script.startup.rules:] - --------> System / Config reloaded <--------.
2018-10-26 07:34:00.036 [INFO ] [arthome.model.script.moverules.rules] - rename rules back in
2018-10-26 07:34:00.048 [INFO ] [] - executed commandLine '/etc/openhab2/scripts/ rules_away rules'
2018-10-26 07:34:37.685 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'abus.rules'
2018-10-26 07:34:48.406 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'alexa.rules'
2018-10-26 07:36:41.368 [INFO ] [.smarthome.model.script.abus.rules: ] - Guard_Mode check: 1
2018-10-26 07:36:41.513 [INFO ] [smarthome.model.script.alexa.rules: ] - Ranzen set to Alexa
2018-10-26 07:36:41.966 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'berling.rules'
2018-10-26 07:37:18.247 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'car.rules'
2018-10-26 07:38:07.077 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'car_state.rules'
2018-10-26 07:38:30.649 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306' takes more than 5000ms.
2018-10-26 07:40:26.729 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306' takes more than 5000ms.
2018-10-26 07:41:45.592 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306' takes more than 5000ms.
2018-10-26 07:42:47.835 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306' takes more than 5000ms.
2018-10-26 07:43:32.403 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.config.discovery.internal.AutomaticInboxProcessor@9741a6' takes more than 5000ms.
2018-10-26 07:43:34.987 [WARN ] [] - Dispatching event to subscriber '' takes more than 5000ms.
2018-10-26 07:43:50.255 [WARN ] [] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306' takes more than 5000ms.
2018-10-26 07:44:39.490 [WARN ] [t.mqtt.internal.MqttBrokerConnection] - MQTT connection to 'mosquitto' was lost: Verbindung wurde getrennt : ReasonCode 32109 : Cause : null
2018-10-26 07:44:36.886 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'EventSubscriber.receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1202306': Java heap space
java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf( ~[?:?]
        at java.lang.AbstractStringBuilder.ensureCapacityInternal( ~[?:?]
        at java.lang.AbstractStringBuilder.append( ~[?:?]
        at java.lang.StringBuffer.append( ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at$16.write( ~[?:?]
        at$16.write( ~[?:?]
        at ~[?:?]
        at$1.write( ~[?:?]
        at$Adapter.write( ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at org.eclipse.smarthome.core.items.GenericItem.sendStateChangedEvent( ~[?:?]
        at org.eclipse.smarthome.core.items.GenericItem.applyState( ~[?:?]
        at org.eclipse.smarthome.core.items.GenericItem.setState( ~[?:?]
        at org.eclipse.smarthome.core.library.items.ImageItem.setState( ~[?:?]
        at org.eclipse.smarthome.core.internal.items.ItemUpdater.receiveUpdate( ~[?:?]
        at ~[?:?]
        at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source) ~[?:?]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke( ~[?:?]
        at java.lang.reflect.Method.invoke( ~[?:?]
        at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect( ~[?:?]
        at ~[?:?]
        at ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker( ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor$ ~[?:?]
2018-10-26 07:45:01.166 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting connection helper to periodically try restoring connection to broker 'mosquitto'
2018-10-26 07:45:12.391 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'mosquitto'

I assume that there is an issue with a specific item / thing.
So, how to find out what


is referring to?

Well it says you’re out of Java heap space. What Java options do you use ? Try adding -Xmx600m.

Thanks for your help.
How do I set this?
And is this the right way to fight the symptoms instead of the root cause?

So I assume there is no way to find out what this is referring to?

I though this would help to identify the binding handling this item or such.

EXTRA_JAVA_OPTS in /etc/default/openhab2.
Use ps -ef|grep java to see if it’s already started with those options.
Execute java -XX:+PrintFlagsFinal -version | findstr HeapSize, too.

It isn’t fighting symptoms, it’s to analyse if you hit the default maximum Java heap size, and if you do then it’s the proper fix, too.

I currently have


but will change it as suggested.

java -XX:+PrintFlagsFinal -version | grep HeapSize


[11:22:44] openhabian@Homer:~$ java -XX:+PrintFlagsFinal -version | grep HeapSize
    uintx ErgoHeapSizeLimit                         = 0                                   {product}
    uintx HeapSizePerGCThread                       = 67108864                            {product}
    uintx InitialHeapSize                          := 16777216                            {product}
    uintx LargePageHeapSizeThreshold                = 134217728                           {product}
    uintx MaxHeapSize                              := 255852544                           {product}
openjdk version "1.8.0_152"
OpenJDK Runtime Environment (Zulu Embedded (build 1.8.0_152-b76)
OpenJDK Client VM (Zulu Embedded (build 25.152-b76, mixed mode, Evaluation)

Here’s a great tutorial for RPI users that includes java memory management.


I am using the following since quite a while (weeks):

EXTRA_JAVA_OPTS="-Xms400m -Xmx650m"

and everything seems to work fine.

However, after activating amazon echo control binding I see heap space issues again:

    2018-11-14 20:15:37.155 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'EventSubscriber.receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@4c0be': Java heap space
java.lang.OutOfMemoryError: Java heap space

So how to find out what ItemUpdater@4c0be is referring to?
Is there a way to identify this item?

1 Like

None that I know of. You can possibly enable big time logging (org.smarthome.eclipse.core.internal to debug) and restart, then grep for lines of that ID in log.
But it’s well possible that the error is unrelated to that item but rather to the binding.

This is fine as well and would help to verify which binding is causing this issue.
I suspect the amazonechocontrol binding…

Just out of curiousity, how many items, bindings and rules do you have?

Items: ~650
Bindings: amazondashbutton,astro,denon1,exec,fritzboxtr0641,harmonyhub,http1,km1001,mqtt1,mqttitude1,neato,netatmo,network,ntp,systeminfo,tankerkoenig,tcp1,wol1,weatherunderground,zwave
rules: 25 rule files with 327 rules

The thing is:
after a restart I got a java heap space error after less than 60 min.

This did not happen last week (AEC binding was removed) - however this was with M4 (have M5 today).
I will do another test with M5 and without AEC binding.

Same thing, with amazon echo control it happened again.

2018-11-16 21:41:44.048 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'EventSubscriber.receive()' on 'org.eclipse.smarthome.core.internal.items.ItemUpdater@1ebbd82': Java heap space java.lang.OutOfMemoryError: Java heap space

Why restart?
Shouldn’t this do the job in karaf without a restart?

log:set DEBUG org.smarthome.eclipse.core.internal

Thanks - I will give it a try.
I am curious if it’s really the amazon echo binding (must be).

It will but he wants you to capture (also) the initial loading of the features during startup (I believe so :slight_smile:)

From what I remember, only during startup you can see some log entries regarding the loading of bundles and features etc.

Alright - thank you very much for the lightning fast response. :slight_smile:

So changing the log level in karaf will persist after restart without touching a loglevel file?
Sorry, I was ususally able to figure out the issues without a log level change

Yes, since any log:set command will be recorded as a setting permanently at the end of $OPENHAB_USERDATA/etc/org.ops4j.pax.logging.cfg

(after this section):

# OSGi appender
log4j2.appender.osgi.type = PaxOsgi = OSGI
log4j2.appender.osgi.filter = *

<it will appear here>

Even if you issue log:set DEFAULT ... it will stay there. I usually go in once a month and remove those autogenerated entries and keep my custom config :stuck_out_tongue:

Makes sense!
Thanks a lot.

I know this file (removed some obsolete stuff from events.log like CPU and Mem messages of system info binding), but I prefer karaf because messing up the config file manually is too easy :smiley:

I assume you’re located in Europe as well if you are up right now.
or US West coast :smiley:

Thanks for your help.

1 Like

Currently, Europe/Athens :sun_with_face: but most of the time, I am in Europe/Bucharest :snowflake: (it’s snowing)

Good morning !

can you post the contents of your rule handling this rules in/out during startup?

Does this WARN appear always after the loading of ‘car_state.rules’ file or it’s random?

You can fix this. Try adding pid:org.openhab.mqtt as the very first line in your $OPENHAB_CONF/services/mqtt.cfg file to see if this WARN goes away.

Athens… nice I am jealous.

It mainly from the forum here to ensure that the rules are loaded after the core is up and running:

val Integer secondsDelay = 240
val String executeCmdBack = "/etc/openhab2/scripts/ rules_away rules"
val String executeCmdAway = "/etc/openhab2/scripts/ rules rules_away"

var Timer renameTimer = null

rule "rename rules back in"
    System started
    logInfo("moverules.rules", "system started triggered")

    if (renameTimer === null) {
        renameTimer = createTimer(now.plusSeconds(secondsDelay)) [|
            logInfo("moverules.rules", "rename rules back in")
            sendTelegram("OH_TeleBot", "moverules -> back")
        logInfo("moverules.rules", "timer created")
        logInfo("moverules.rules", "timer already existing")

	if(System_started.state == ON) {
	else {
	logInfo("startup.rules:", "--------> System / Config reloaded <--------.")
	sendTelegram("OH_TeleBot", "System / Config wurde neu geladen.")

rule "rename rules away"
System shuts down
logInfo("moverules.rules", "rename rules away")
sendTelegram("OH_TeleBot", "moverules -> away")

No, that’s random.