openHAB 3 runs out of memory / java heap space errors, CPU 100%+ after a few hours

OpenHabian 1.6.2 (the latest release) running OpenHab 3.0.0 on my Pi3 B+. Was previously running OH 2.5 fine. I wiped and burned the new image, starting fresh without restoring old files. No textual files from OH2. All configured using “the new way” through the main UI.

The installation goes fine, it begins working great. But after several hours, TOP shows the openhab process at 100% or higher. And it’s throwing heap space and out of memory errors. The UI ceases to function, rules and scripts cease to function, but the item updates all keep rolling in as seen in the event logs.

When this happens, I will SSH into the pi, stop the service, clear the cache, and reboot. This cycle repeats. I thought maybe something was buggered in the install, so I have no actually burned and reinstalled fresh three times now. This occured in RC1, RC2, and 3.0.0.

Bindings installed and in use are z-wave, network, DSC Alarm, & Astro. No persistence installed yet, and no other add ons installed yet.

Here is openhab.log beginning where things go downhill this morning. This is what it looks like every time. The log ends where I just got home and pulled it.

2020-12-22 09:25:23.491 [ERROR] [enhab.core.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException: Total timeout 5000 ms elapsed
2020-12-22 09:25:23.499 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID '8601a93f5c' failed: cannot invoke method public java.lang.String[] java.lang.String.split(java.lang.String) on null
2020-12-22 11:46:44.180 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 12:15:24.830 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.monitor.internal.EventLogger@a42521' takes more than 5000ms.
2020-12-22 12:56:28.691 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:16:50.357 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.rest.sse.internal.listeners.SseEventSubscriber@1bec6eb' takes more than 5000ms.
2020-12-22 13:24:00.216 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.monitor.internal.EventLogger@a42521' takes more than 5000ms.
2020-12-22 13:31:52.779 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:35:39.572 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.monitor.internal.EventLogger@a42521' takes more than 5000ms.
2020-12-22 13:36:34.262 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:37:39.900 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.io.monitor.internal.EventLogger@a42521' takes more than 5000ms.
2020-12-22 13:37:49.089 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:38:07.944 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:39:34.545 [ERROR] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance
2020-12-22 13:39:34.563 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 2c3a09a2-255b-4144-881d-43d732cc0f9c, base URL = http://localhost:8080)
2020-12-22 13:40:22.795 [ERROR] [enhab.core.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException: Total timeout 5000 ms elapsed
2020-12-22 13:43:10.522 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 13:47:54.070 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.thing.internal.CommunicationManager@1db8381' takes more than 5000ms.
2020-12-22 14:01:23.352 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.thing.internal.CommunicationManager@1db8381' takes more than 5000ms.
2020-12-22 14:03:33.484 [WARN ] [ab.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.openhab.core.internal.items.ItemUpdater@c6bcd7' takes more than 5000ms.
2020-12-22 14:43:01.879 [ERROR] [internal.handler.ScriptActionHandler] - Script execution of rule with UID '8601a93f5c' failed: cannot invoke method public java.lang.String[] java.lang.String.split(java.lang.String) on null
2020-12-22 14:42:34.894 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 14:46:45.360 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 14:52:04.706 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 14:57:22.712 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:13:33.295 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:18:12.043 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:18:48.507 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:21:51.181 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:32:04.757 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 15:42:48.575 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:06:10.085 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:05:16.792 [WARN ] [e.automation.internal.RuleEngineImpl] - Fail to execute action: script
java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:12:57.796 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:11:26.399 [WARN ] [e.jetty.util.thread.QueuedThreadPool] - 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:20:16.133 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule '9027ab6b2a': 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:26:04.909 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:27:44.828 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:27:53.707 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:29:33.758 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:29:42.637 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:30:09.434 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:32:51.733 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:32:51.737 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:32:51.740 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:33:28.367 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:34:05.373 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:34:14.516 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:35:18.179 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:36:12.769 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:36:22.485 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:36:40.575 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:36:59.391 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:37:17.473 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:37:26.570 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:37:45.266 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:38:30.656 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:38:57.622 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:39:15.448 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:39:34.088 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:39:43.080 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:39:52.070 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:40:01.865 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:40:10.925 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:40:10.933 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:40:19.905 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:45:44.972 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:49:49.032 [WARN ] [org.eclipse.jetty.io.ManagedSelector] - java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:48:29.166 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 16:56:30.115 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 16:48:29.166 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:00:50.993 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:07:58.015 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:08:35.334 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:10:00.560 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:10:10.566 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 17:11:39.851 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:27:23.524 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 17:27:32.570 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception: 
java.lang.OutOfMemoryError: Java heap space
2020-12-22 17:30:15.960 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 17:35:01.735 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 17:40:01.901 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'
2020-12-22 17:45:18.415 [ERROR] [e.automation.internal.RuleEngineImpl] - Failed to execute rule ‘5bc9a0b526' with status 'RUNNING'

Here’s the openhabian terminal welcome screen as it was when I just got home.

###############################################################################
###############  openHABianDevice  ############################################
###############################################################################
##        Ip = 192.168.0.100
##   Release = Raspbian GNU/Linux 10 (buster)
##    Kernel = Linux 5.4.79-v7+
##  Platform = Raspberry Pi 3 Model B Plus Rev 1.3
##    Uptime = 0 day(s). 12:22:21
## CPU Usage = 25.06% avg over 4 cpu(s) (4 core(s) x 1 socket(s))
##  CPU Load = 1m: 1.08, 5m: 1.02, 15m: 1.01
##    Memory = Free: 0.11GB (12%), Used: 0.79GB (88%), Total: 0.90GB
##      Swap = Free: 0.68GB (100%), Used: 0.00GB (0%), Total: 0.68GB
##      Root = Free: 25.24GB (90%), Used: 2.52GB (10%), Total: 28.98GB
##   Updates = 0 apt updates available.
##  Sessions = 1 session(s)
## Processes = 136 running processes of 32768 maximum processes
###############################################################################

I have several rules that create a bunch of vals and vars, which are used to update string items for display purposes (mostly environmental related). They fire quite often as environmental sensors are updated. Could something in these rules be blowing out the memory? Here’s an example of the rules that fire often and have a lot of strings.

// Read temp & humidity sensors as integers
val int temp_upper =   (UpperMS6_Sensortemperature.state as Number).intValue
val int temp_lower =   (LowerMS6_Sensortemperature.state as Number).intValue
val int temp_gar =     (GarageMS6_Sensortemperature.state as Number).intValue 
val int temp_util =    (UtilityRoomMonitor_Sensortemperature.state as Number).intValue
val int humid_upper =  (UpperMS6_Sensorrelativehumidity.state as Number).intValue
val int humid_lower =  (LowerMS6_Sensorrelativehumidity.state as Number).intValue
val int humid_gar =    (GarageMS6_Sensorrelativehumidity.state as Number).intValue

// Combing temp & humidity values into readable strings
val String env_string_upper =   temp_upper + "°F/" + humid_upper + "%"
val String env_string_lower =   temp_lower + "°F/" + humid_lower + "%"
val String env_string_garage =  temp_gar + "°F/" + humid_gar + "%"
val String env_string_util =    temp_util + "°F"
val String env_string_indoor =  "Upper " + env_string_upper + " | Lower " + env_string_lower + " | Garage " + env_string_garage + " | Utility Room " + env_string_util

// Update any items that have changed
if (env_upper_string.state != env_string_upper)            { env_upper_string.postUpdate(env_string_upper) }
if (env_lower_string.state != env_string_lower)            { env_lower_string.postUpdate(env_string_lower) }
if (env_garage_string.state != env_string_garage)          { env_garage_string.postUpdate(env_string_garage) }
if (env_indoor_string.state != env_string_indoor)          { env_indoor_string.postUpdate(env_string_indoor) }

Retrieves data from my weather station

// Retrieve the CSV file from server and take the last line (only has 2 rows: a header and data)
// Example of CSV file's two rows:
// temp,dewpoint,winddir,wind,windgust,windchill,heatindex,rain,windstring, tempstring,humidity,epoch
// 34.5,30.7,SSE,5,9,31,35,0.00,SSE 5 Gusting 9 mph, 35 | DP 31 | Chill 31,86.0,1608483894
  val csv = sendHttpGetRequest("http://192.168.0.10/openhab_data.csv").split("\n")
  val lastLine = csv.get(csv.size-1).split(",")

// Read the values from the CSV file, converting all to whole numbers only (no decimal points)
  val int     temp_new =          (Float::parseFloat(lastLine.get(0).trim) as Number).intValue
  val int     dp_new =            (Float::parseFloat(lastLine.get(1).trim) as Number).intValue
  val String  windDir_new =       lastLine.get(2).trim
  val int     windSpeed_new =     (Float::parseFloat(lastLine.get(3).trim) as Number).intValue
  val int     windGust_new =      (Float::parseFloat(lastLine.get(4).trim) as Number).intValue
  val int     windChill_new =     (Float::parseFloat(lastLine.get(5).trim) as Number).intValue
  val int     heatIndex_new =     (Float::parseFloat(lastLine.get(6).trim) as Number).intValue
  val Number  rain24hr_new =      Float::parseFloat(lastLine.get(7).trim) as Number
  // val String  windString_new =    lastLine.get(8).trim //not used for now
  // val String  tempString_new =    lastLine.get(9).trim //not used for now
  val int     humid_new =         (Float::parseFloat(lastLine.get(10).trim) as Number).intValue
  // val int     epoch_new =         (Float::parseFloat(lastLine.get(11).trim) as Number).intValue // not used for now
  var int     feelsLike_new  =    temp_new

// Set the feels like temp to either wind chill or heat index if different than the temperature
  if (windChill_new < temp_new) {
    // Use the wind chill for feels like
    feelsLike_new = windChill_new
  } else if (heatIndex_new > temp_new) {
    // Use the heat index for feels like
    feelsLike_new = heatIndex_new
  }

// Temperature string (show dewpoint if >55, and show feels like if difference > 5)
  var String temp_string_new1 = temp_new + "°F"
  if (dp_new > 55) {
    temp_string_new1 = temp_string_new1 + " | DP " + dp_new + "°F"
  }
  
  if (Math::abs((temp_new as Number).floatValue - (feelsLike_new as Number).floatValue) as Number >= 5) {
    temp_string_new1 = temp_string_new1 + "| Feels Like " + feelsLike_new + "°F"
  }

// Wind string (supress wind speed <3mph and gust factors <3mph)
  var String wind_string_new1
  
  if (windSpeed_new <= 3 && windGust_new <= 3) {
    wind_string_new1 = "Calm"
  } else if (windGust_new - windSpeed_new <= 3) {
    wind_string_new1 = windDir_new + " " + windSpeed_new + "mph"
  } else {
    wind_string_new1 = windDir_new + " " + windSpeed_new + " Gusting " + windGust_new + "mph"
  }

// Full outdoor wx string, including temp and wind strings
  var String wx_string = temp_string_new1 + " | Wind " + wind_string_new1


// Update items, but only if value is changed to reduce writes
  if (meteo_temp.state == NULL || (meteo_temp.state as Number) != temp_new)                  {meteo_temp.postUpdate(temp_new)}
  if (meteo_dp.state == NULL || (meteo_dp.state as Number) != dp_new)                        {meteo_dp.postUpdate(dp_new)}
  if (meteo_wind_dir.state == NULL || meteo_wind_dir.state != windDir_new)                   {meteo_wind_dir.postUpdate(windDir_new)}
  if (meteo_wind_speed.state == NULL || (meteo_wind_speed.state as Number) != windSpeed_new) {meteo_wind_speed.postUpdate(windSpeed_new)}
  if (meteo_wind_gust.state == NULL || (meteo_wind_gust.state as Number) != windGust_new)    {meteo_wind_gust.postUpdate(windGust_new)}
  if (meteo_wind_chill.state == NULL || (meteo_wind_chill.state as Number) != windChill_new) {meteo_wind_chill.postUpdate(windChill_new)}
  if (meteo_heat_index.state == NULL || (meteo_heat_index.state as Number) != heatIndex_new) {meteo_heat_index.postUpdate(heatIndex_new)}
  if (meteo_rain24hr.state == NULL || (meteo_rain24hr.state as Number) != rain24hr_new)      {meteo_rain24hr.postUpdate(rain24hr_new)}
  if (meteo_wind_string.state == NULL || meteo_wind_string.state != wind_string_new1)        {meteo_wind_string.postUpdate(wind_string_new1)}
  if (meteo_temp_string.state == NULL || meteo_temp_string.state != temp_string_new1)        {meteo_temp_string.postUpdate(temp_string_new1)}
  if (meteo_humidity.state == NULL || (meteo_humidity.state as Number) != humid_new)         {meteo_humidity.postUpdate(humid_new)}
  if (meteo_feels_like.state == NULL || (meteo_feels_like.state as Number) != feelsLike_new) {meteo_feels_like.postUpdate(feelsLike_new)}
  if (meteo_wx_string.state == NULL || meteo_wx_string.state != wx_string)                   {meteo_wx_string.postUpdate(wx_string)}

Updates a text string item with the HVAC state

// Pick thermostat heating or cooling setpoint to display; show current temp if off
val int tstat_temp =   (HVACThermostat_Sensortemperature.state as Number).intValue
val Number tstat_mode =   HVACThermostat_Thermostatmode.state as Number
var int tstat_setpoint
if (tstat_mode == 1) {
  tstat_setpoint =     (HVACThermostat_Setpointheating.state as Number).intValue
} else if (tstat_mode == 2) {
  tstat_setpoint =     (HVACThermostat_Setpointcooling.state as Number).intValue
} else {
  tstat_setpoint = tstat_temp
}

// Thermostat operating state string
val Number tstat_state = HVACThermostat_ThermostatOperatingState.state as Number
var String tstat_state_string
if (tstat_state == 0) {
  tstat_state_string = "Idle"
} else if (tstat_state == 1) {
  tstat_state_string = "Heating"
} else if (tstat_state == 2) {
  tstat_state_string = "Cooling"
} else {
  tstat_state_string = "Unknown"
}

// Thermostat fan mode string
val Number tstat_fan_mode =  HVACThermostat_Thermostatfanmode.state as Number
var String tstat_fan_mode_string
if (tstat_fan_mode == 0) {
  tstat_fan_mode_string = "Fan Auto"
} else if (tstat_fan_mode == 1) {
  tstat_fan_mode_string = "Fan On"
} else if (tstat_fan_mode == 6) {
  tstat_fan_mode_string = "Fan Circ"
} else {
  tstat_fan_mode_string = "Fan Unknown"
}

// String of full thermostat status
val String env_string_tstat =   "Setpoint " + tstat_setpoint + "°F | Temp " + tstat_temp + "°F | " + tstat_fan_mode_string + " | " + tstat_state_string

// Update any items that have changed
if (env_string_hvac_state.state != env_string_tstat) { env_string_hvac_state.postUpdate(env_string_tstat) }

Updates a text string with the DSC alarm system state

var logger = Java.type('org.slf4j.LoggerFactory').getLogger('org.openhab.rule.' + ctx.ruleUID);

if (itemRegistry.getItem('DSCPartition1_PartitioninAlarm').getState() == 'ON' && itemRegistry.getItem('DSCKeypad_KeypadFireLED').getState() > 0) {
  events.postUpdate('partition_status_text','FIRE ALARM')
} else if (itemRegistry.getItem('DSCPartition1_PartitioninAlarm').getState() == 'ON' && itemRegistry.getItem('DSCKeypad_KeypadFireLED').getState() == 0) {
  events.postUpdate('partition_status_text','SECURITY ALARM')
} else if (itemRegistry.getItem('DSCPartition1_PartitionExitDelay').getState() == 'ON') {
  events.postUpdate('partition_status_text','Exit Delay')
} else if (itemRegistry.getItem('DSCPartition1_PartitionEntryDelay').getState() == 'ON') {
  events.postUpdate('partition_status_text','Entry Delay')
} else if (itemRegistry.getItem('DSCPartition1_PartitionArmMode').getState() == '1') {
  events.postUpdate('partition_status_text','Armed Away')
} else if (itemRegistry.getItem('DSCPartition1_PartitionArmMode').getState() == '2') {
  events.postUpdate('partition_status_text','Armed Stay')
} else if (itemRegistry.getItem('DSCPartition1_PartitionArmMode').getState() == '3') {
  events.postUpdate('partition_status_text','Armed Away Instant')
} else if (itemRegistry.getItem('DSCPartition1_PartitionArmMode').getState() == '4') {
  events.postUpdate('partition_status_text','Armed Stay Instant')
} else if (itemRegistry.getItem('DSCPartition1_PartitionArmMode').getState() == '0') {
  events.postUpdate('partition_status_text','Disarmed')
} else {
  events.postUpdate('partition_status_text','Unknown')
}

I don’t see anyone else having this problem so I assume this isn’t an epic OpenHAB failure. Something I’m doing must be wrong. But I don’t see what as I’m pretty basic here.

Thx

As I see it, you have 2 paths forward to try to pinpoint what’s causing the issue.

  • Start with a completely clean install, then slowly add things one at a time to determine what causes the issue.

  • Start with your current system, then slowly remove things one at a time to determine at what point the system becomes stable.

Neither of these approaches will yield a quick solution, but it’s the only way I know to isolate the cause.

BTW, you say you don’t have openhabcloud installed, but there’s evidence in your log that the openhabcloud bundle is installed.

2020-12-22 13:39:34.545 [ERROR] [io.openhabcloud.internal.CloudClient] - Error connecting to the openHAB Cloud instance
2020-12-22 13:39:34.563 [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 2c3a09a2-255b-4144-881d-43d732cc0f9c, base URL = http://localhost:8080)

Oh yes, I just put openhab cloud on last night, because I was going to have to head into the office today and wanted remote access. This was happening without openhab cloud too.

I have disabled the rules that trigger those three scripts as of this evening to see if it keeps working properly. That would at least get my process of elimination going in the right direction. But one of those scripts being the culprit is simply a guess on my part right now.

It’s been about 14 hours now with those three rules/scripts disabled and it continues to operate properly. So I think it’s reasonable to conclude the problem is in one of those three rules.

Can anyone take a look at this rules and see if anything stands out as problematic?

The weather station script (DSL) that parses a CSV file takes about 10 seconds to run. The indoor sensor script takes about 5-6 seconds. The DSC Alarm script takes a second or two.

Also, I’m doing this, checking to see if the new sensor reading has changed before posting the update to the item. My thought was to save writing a pointless update, but I’m wondering if this is using more effort than it’s worth.
if (meteo_temp.state == NULL || (meteo_temp.state as Number) != temp_new) {meteo_temp.postUpdate(temp_new)}

I’m by far an expert, but I know openHAB slows considerably when using primitives in rules. I think the recommendation is to either avoid using primitives altogether, or cast at the very last moment.

I’m afraid I’ve got nothing more on this myself, but a search on this forum on the subject of primitives might help?

Don’t clear the cache. It’ll just force the reinstallation of your bindings and make OH that much slower to come up next time. Especially since it’s not doing any good.

If you’re on OH 3 you have rrd4j by default with a strategy of every minute, every change and restore on startup for all supported Items.

Anything is possible but I think that’s unlikely.

Nothing stands out as problematic except…

This is a problem mainly with loading and parsing of .rules files. But I don’t think it makes the rules run slower. But it would be a really good idea to remove the primitives. Never use a primitive or even specific they type of something unless you have to. And if you have to wait for the last possible moment to convert it to a primitive. Leave everything as Numbers instead.

It may not be slowing down you execution but it could be adding minutes or more to how long it takes to load and parse your rules. And if Oh 3 works like OH 2, every time there is a change to one of your .items or .rules files, it will reload them all. If it’s already reloading the files, it will wait for that to finish and then reload them again! If you edit a bunch of files in sequence, you can bring your machine to it’s knees for a couple of hours.

I don’t know if this is still a problem for OH 3 or not but it’s something to watch for.

With those scripts disabled, it continued to run fine all day. I cleaned them up a bit to use less primatives (I think). Turned them back on, and the same thing happened. I enabled the thermostat and indoor environmental scripts (not the weather station).

So the problem is definitely with these scripts.

That seems to be good evidence. But except for the primitives there is nothing in those scripts that appear possible to create a memory leak or the CPU to go out of control. There are no loops, nothing is creating a lot of variables that don’t get thrown away.

I think your best bet at this point is to file an issue.

One more process of elimination to try here. For the thermostat script and indoor environment scripts that were in old DSL, I deleted them and made new ones in ECMA. I have the weather station DSL script disabled for now.

So I’m going to see if it can get through the day without exploding. If the problem seems to go away, I think that points to a memory issue with OH3 and DSL scripts?

Are those DSL scripts created via the UI or from files? I seem to have similar problems with those from the UI…

The UI. And I am quickly realizing there is a potential huge problem with this. These two DSL scripts, composed in the UI, took 4 to 7 seconds to execute. During those 4-7 seconds, the CPU would be over 100%. And after several hours of normal operation (scripts running every 5-10 minutes), the whole thing would just keel over dead out of memory and CPU pegged.

The exact same operation performed by an ECMA script composed in the UI executes so fast the indicator doesn’t even change to running. This has been running for hours now honestly this is the best I’ve ever seen my install of OH3 operate. Everything it is does is instant and nothing is bogging down.

What or why this problem exists is well over my head, but process of elimination here seems to suggest it exists.

You posted only parts of the rules, which triggers are you using and with what settings?

That’s what i also saw. In my case the simplest rules from the UI in DSL take up to 10s with high CPU load, but not neccessarely high memory usage. I reduced how often these rules run but i think i only increased the time between the crashes.

Those are scripts, in their entirety. There are separate rules that trigger them. Those triggers are either item state changes, or an every 5 minutes cron.

1 Like

I experience the same problem. I’ve created a new topic, but I think I can let it merge with this topic.
[OH3] high cpu load, unresponsive OH

Since i now moved all my DSL rules in files again, my cpu load looks stable and extremely low! I think that did the trick in my case!

(same rules, same triggers)

One git issue has to be declared if not existing.

1 Like

I though I have my problems tackled but I still have a high CPU load.
Can someone run a

shell:threads - - list

in the karaf console and see what are the top CPU time consumers? For me DirWatcher and RuleRefresher are suspiciously high!
I use file-only DSL rules, but I also use jython with the (fixed) helper libraries…
When watching the event stream in the debug sidebar, I see sometimes that rules get reloaded even though I did not touch the configuration…
I also still see some org.eclipse.x bundles when I do bundle:list -s. Shouldn’t they be gone?

I tried one more thing and it looks like it helped:

sudo apt purge openhab2

Followed by a reboot.
I upgraded with the openhabian config tool, but somehow the were still leftovers… Now it’s running like a charm.

For me this doesn’t apply unfortunately, because I run OH3 in a docker container, so I have a “clean” environment

in my case the RXTXPortMonitor is the highest, but none of the threads are suspiciously high.