After I switched to a Linux environment with my OpenHAB installation, I can see weird dropouts in HTTP binding value readings which I didn’t see (or just didn’t recognize?) on Windows. I have some Item s configured (about eight for that hardware) that get their value with HTTP binding, see example above. Measured value is net voltage with two decimals, so this value will change on every measure. I configured a granularity of 10 seconds (10000 milliseconds), and for debugging purposes I configured a EveryChange persistence for this item. After OpenHAB running some time, I can see the dropouts.
On 2018-12-13 10:16 I restarted OpenHAB and the dropouts disappeared (see lower right pane, one log every 10 to 11 seconds):
Okay I figured it out. I issued a log:set DEBUG org.openhab.binding.http on command line and got some logs:
openhab.log
2018-12-17 11:56:41.915 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Voltage' is about to be refreshed now
2018-12-17 11:56:41.964 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '227.75'
2018-12-17 11:56:41.964 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Current' is about to be refreshed now
2018-12-17 11:56:42.048 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '0.18'
2018-12-17 11:56:42.048 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:42.048 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:42.081 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:42.082 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:42.082 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:56:42.114 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:43.114 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:56:43.115 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:56:43.139 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:43.140 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:56:43.140 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:56:43.160 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:43.160 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:56:43.160 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:56:43.179 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:43.180 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:56:43.180 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:56:43.202 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:43.202 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:43.203 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:43.221 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:43.222 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:43.222 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:56:43.241 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:44.242 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:56:44.242 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:56:44.262 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:44.263 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:56:44.263 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:56:44.282 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:44.283 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:56:44.283 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:56:44.301 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:44.302 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:56:44.302 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:56:44.335 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:44.335 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:44.335 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:44.373 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:44.374 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:44.374 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:56:44.392 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:45.393 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:56:45.393 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:56:45.413 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:45.413 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:56:45.413 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:56:45.436 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:45.436 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:56:45.436 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:56:45.459 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:45.460 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:56:45.460 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:56:45.513 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:45.514 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:45.514 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:45.534 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:45.535 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:45.535 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:56:45.554 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:46.554 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:56:46.554 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:56:46.577 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:46.578 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:56:46.578 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:56:46.596 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:46.597 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:56:46.597 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:56:46.616 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:46.616 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:56:46.616 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:56:46.635 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:46.653 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:46.653 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:46.684 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:46.685 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:46.685 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:56:46.715 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.716 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:56:47.716 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:56:47.738 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.738 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:56:47.739 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:56:47.760 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.760 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:56:47.760 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:56:47.800 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.800 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:56:47.801 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:56:47.856 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.856 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-17 11:56:47.856 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 11:56:47.875 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 11:56:47.876 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:47.876 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:58:58.927 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:58:59.928 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-17 11:58:59.928 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-17 11:58:59.952 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:58:59.952 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-17 11:58:59.953 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-17 11:58:59.976 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:58:59.976 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 11:58:59.976 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 11:58:59.996 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:58:59.996 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'SV_Jenkins_2_json' is fetched from cache
2018-12-17 11:58:59.997 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'jenkins2Cache' ('https://[...]/api/json')
2018-12-17 11:59:00.671 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '[...]'
2018-12-17 11:59:00.672 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'SV_Jenkins_1_json' is fetched from cache
2018-12-17 11:59:00.673 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'jenkins1Cache' ('https://[...]/api/json')
2018-12-17 11:59:01.299 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '[...]'
2018-12-17 11:59:01.300 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:59:01.300 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:59:01.324 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:59:01.325 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Voltage' is about to be refreshed now
2018-12-17 11:59:01.374 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '228.30'
2018-12-17 11:59:01.375 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Current' is about to be refreshed now
2018-12-17 11:59:01.423 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '0.18'
So because of updating cache for 'ALL4176_Relais4StatusCache at 11:56:47.876 did take two minutes all other HTTP requests got delayed, correct? Or what did happen here?
Is it possible to configure more than one worker?
I analyzed the logs from yesterday, it’s always the same:
2018-12-17 11:53:27.344 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais5Status' is fetched from cache
2018-12-17 11:53:27.345 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais5StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=5&get')
2018-12-17 11:55:38.221 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 11:56:47.876 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 11:56:47.876 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 11:58:58.927 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 12:04:54.569 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 12:04:54.569 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 12:07:04.303 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 12:10:19.941 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1RedLampStatus' is fetched from cache
2018-12-17 12:10:19.941 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-17 12:12:29.931 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-17 12:14:57.226 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-17 12:14:57.227 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-17 12:17:06.415 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-17 12:17:34.704 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-17 12:17:34.705 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-17 12:19:44.110 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
Yeah, one could use an external script - but why, when OpenHAB provides HTTP functionality? It would be better to fix that than to write someting external.
I did a log with TRACE some minutes ago, but I can only analyze that later, stay tuned.
So here are the logs with TRACE level. Seems as the caches are a bit intereaved, but I still can’t see a root cause:.
Outages are at the end of each log, you can see the timestamps.
2018-12-18 10:51:29.851 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Current' is about to be refreshed now
2018-12-18 10:51:29.901 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is '0.15'
2018-12-18 10:51:29.902 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais1Status' is fetched from cache
2018-12-18 10:51:29.902 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais1StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=1&get')
2018-12-18 10:51:29.902 [TRACE] [ab.binding.http.internal.HttpBinding] - Couldn't find matching binding provider [itemName=ALL4176_Current, command=CHANGED]
2018-12-18 10:51:29.932 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-18 10:51:29.932 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais4Status' is fetched from cache
2018-12-18 10:51:29.932 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais4StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=4&get')
2018-12-18 10:51:29.933 [TRACE] [ab.binding.http.internal.HttpBinding] - Couldn't find matching binding provider [itemName=ALL4176_Relais1Status, command=CHANGED]
2018-12-18 10:51:29.982 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-18 10:51:29.983 [TRACE] [ab.binding.http.internal.HttpBinding] - Couldn't find matching binding provider [itemName=ALL4176_Relais4Status, command=CHANGED]
2018-12-18 10:51:30.983 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais2Status' is fetched from cache
2018-12-18 10:51:30.983 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais2StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=2&get')
2018-12-18 10:51:31.003 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'ON'
2018-12-18 10:51:31.003 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais3Status' is fetched from cache
2018-12-18 10:51:31.003 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais3StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=3&get')
2018-12-18 10:51:31.004 [TRACE] [ab.binding.http.internal.HttpBinding] - Couldn't find matching binding provider [itemName=ALL4176_Relais2Status, command=CHANGED]
2018-12-18 10:53:41.330 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
2018-12-18 10:53:41.331 [DEBUG] [ab.binding.http.internal.HttpBinding] - item 'ALL4176_Relais6Status' is fetched from cache
2018-12-18 10:53:41.331 [TRACE] [ab.binding.http.internal.HttpBinding] - Couldn't find matching binding provider [itemName=ALL4176_Relais3Status, command=CHANGED]
2018-12-18 10:53:41.331 [DEBUG] [ab.binding.http.internal.HttpBinding] - updating cache for 'ALL4176_Relais6StatusCache' ('http://<ipaddress>/xml/jsonswitch.php?id=6&get')
2018-12-18 10:53:41.361 [DEBUG] [ab.binding.http.internal.HttpBinding] - transformed response is 'OFF'
Some days later I finally restarted OpenHAB and target hardware - and still experienced the outages.
Then finally on December 27th in the middle of the night, it worked again (until now).
I didn’t change anything there, openhab.log and events.log don’t tell interesting things for that time, even syslog is empty between 2:00 and 3:00 am.
Update earlier than I thought… About 12:05 the server started to go wild. I also have a network:pingdevice set up for the device, this was always ON and now started to switch to OFF and back about every second minute - despites a (system) ping worked flawlessly during this time. Updates to Influxdb also got less and less.
I did a OpenHAB restart at about 12:30 and now it works again - I suppose that’s the behaviour I observed at the beginning of this thread.
==> /log/openhab2/openhab.log <==
2019-01-02 12:27:08.173 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@6b47eff4' takes more than 5000ms.
2019-01-02 12:30:12.722 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception
java.lang.OutOfMemoryError: Java heap space
at java.io.BufferedReader.<init>(BufferedReader.java:105) ~[?:?]
at java.io.BufferedReader.<init>(BufferedReader.java:116) ~[?:?]
at java.nio.file.Files.newBufferedReader(Files.java:2785) ~[?:?]
at java.nio.file.Files.readAllLines(Files.java:3202) ~[?:?]
at oshi.util.FileUtil.readFile(FileUtil.java:75) ~[?:?]
at oshi.util.FileUtil.readFile(FileUtil.java:56) ~[?:?]
at oshi.software.os.linux.LinuxFileSystem.getFileStores(LinuxFileSystem.java:133) ~[?:?]
at org.openhab.binding.systeminfo.internal.model.OshiSysteminfo.getStorageUsedPercent(OshiSysteminfo.java:251) ~[?:?]
at org.openhab.binding.systeminfo.handler.SysteminfoHandler.getInfoForChannel(SysteminfoHandler.java:400) ~[?:?]
at org.openhab.binding.systeminfo.handler.SysteminfoHandler.publishDataForChannel(SysteminfoHandler.java:249) ~[?:?]
at org.openhab.binding.systeminfo.handler.SysteminfoHandler.publishData(SysteminfoHandler.java:242) ~[?:?]
at org.openhab.binding.systeminfo.handler.SysteminfoHandler.lambda$0(SysteminfoHandler.java:221) ~[?:?]
at org.openhab.binding.systeminfo.handler.SysteminfoHandler$$Lambda$237/192177765.run(Unknown Source) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
2019-01-02 12:30:40.242 [ERROR] [io.openhabcloud.internal.CloudClient] - Socket.IO error: {}
io.socket.engineio.client.EngineIOException: websocket error
at io.socket.engineio.client.Transport.onError(Transport.java:71) [211:org.openhab.io.openhabcloud:2.3.0]
at io.socket.engineio.client.transports.WebSocket.access$500(WebSocket.java:28) [211:org.openhab.io.openhabcloud:2.3.0]
at io.socket.engineio.client.transports.WebSocket$2$5.run(WebSocket.java:150) [211:org.openhab.io.openhabcloud:2.3.0]
at io.socket.thread.EventThread$2.run(EventThread.java:80) [211:org.openhab.io.openhabcloud:2.3.0]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.io.EOFException
at okio.RealBufferedSource.require(RealBufferedSource.java:59) ~[?:?]
at okio.RealBufferedSource.readByte(RealBufferedSource.java:72) ~[?:?]
at okhttp3.internal.ws.WebSocketReader.readHeader(WebSocketReader.java:115) ~[?:?]
at okhttp3.internal.ws.WebSocketReader.processNextFrame(WebSocketReader.java:104) ~[?:?]
at okhttp3.internal.ws.RealWebSocket.readMessage(RealWebSocket.java:97) ~[?:?]
at okhttp3.ws.WebSocketCall.createWebSocket(WebSocketCall.java:152) ~[?:?]
at okhttp3.ws.WebSocketCall.access$000(WebSocketCall.java:41) ~[?:?]
at okhttp3.ws.WebSocketCall$1.onResponse(WebSocketCall.java:97) ~[?:?]
at okhttp3.RealCall$AsyncCall.execute(RealCall.java:126) ~[?:?]
at okhttp3.internal.NamedRunnable.run(NamedRunnable.java:32) ~[?:?]
... 3 more
2019-01-02 12:30:38.117 [WARN ] [eclipse.jetty.servlet.ServletHandler] - Error for /rest/sitemaps/events/subscribe
java.lang.OutOfMemoryError: Java heap space
2019-01-02 12:30:38.116 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception
java.lang.OutOfMemoryError: Java heap space
2019-01-02 12:33:15.076 [WARN ] [eclipse.jetty.servlet.ServletHandler] -
javax.servlet.ServletException: A MultiException has 1 exceptions. They are:
1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_1,2,18838638) has been shut down
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:489) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:427) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:388) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:341) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:228) [167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
at com.eclipsesource.jaxrs.publisher.internal.ServletContainerBridge.service(ServletContainerBridge.java:76) [15:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:848) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:584) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:71) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548) [82:org.eclipse.jetty.security:9.3.21.v20170918]
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [85:org.eclipse.jetty.servlet:9.3.21.v20170918]
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80) [183:org.ops4j.pax.web.pax-web-jetty:6.0.9]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.Server.handle(Server.java:534) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:333) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [84:org.eclipse.jetty.server:9.3.21.v20170918]
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [76:org.eclipse.jetty.io:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [87:org.eclipse.jetty.util:9.3.21.v20170918]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: org.glassfish.hk2.api.MultiException: A MultiException has 1 exceptions. They are:
1. java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_1,2,18838638) has been shut down
at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:106) ~[?:?]
at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173) ~[?:?]
at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526) ~[?:?]
at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) ~[170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) ~[170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) ~[167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
... 31 more
Caused by: java.lang.IllegalStateException: ServiceLocatorImpl(__HK2_Generated_1,2,18838638) has been shut down
at org.jvnet.hk2.internal.ServiceLocatorImpl.checkState(ServiceLocatorImpl.java:2288) ~[?:?]
at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandleImpl(ServiceLocatorImpl.java:629) ~[?:?]
at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:622) ~[?:?]
at org.jvnet.hk2.internal.ServiceLocatorImpl.getServiceHandle(ServiceLocatorImpl.java:640) ~[?:?]
at org.jvnet.hk2.internal.FactoryCreator.getFactoryHandle(FactoryCreator.java:103) ~[?:?]
at org.jvnet.hk2.internal.FactoryCreator.dispose(FactoryCreator.java:173) ~[?:?]
at org.jvnet.hk2.internal.SystemDescriptor.dispose(SystemDescriptor.java:526) ~[?:?]
at org.glassfish.jersey.process.internal.RequestScope$Instance.remove(RequestScope.java:532) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope$Instance.release(RequestScope.java:549) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:319) ~[169:org.glassfish.jersey.core.jersey-common:2.22.2]
at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) ~[170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) ~[170:org.glassfish.jersey.core.jersey-server:2.22.2]
at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:473) ~[167:org.glassfish.jersey.containers.jersey-container-servlet-core:2.22.2]
... 31 more
… and yes, I can see a drop in memory usage (and swap usage I added before restart).
So it looks like a plain memory leak?
… and same symptoms again starting at 17:01 - I didn’t change anything but the added swap used Item and logging with persistence. Why is OpenHAB running wild?
(data between 17:34 and 18:00 is invalid because it’s interpolated linearly)
It ran for about half a month, and now isn’t even able to run half a day?
Logs:
2019-01-02 17:01:56.737 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@3cb00f4d' takes more than 5000ms.
2019-01-02 17:14:08.005 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@3cb00f4d' takes more than 5000ms.
2019-01-02 17:18:36.365 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@699eab9' takes more than 5000ms.
2019-01-02 17:21:35.989 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.internal.items.ItemUpdater@3cb00f4d' takes more than 5000ms.
2019-01-02 17:26:59.872 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.CommunicationManager@a3de4c9' takes more than 5000ms.
2019-01-02 17:27:15.972 [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber 'org.eclipse.smarthome.io.monitor.internal.EventLogger@699eab9' takes more than 5000ms.
2019-01-02 17:27:15.972 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'EventSubscriber.receive()' on 'org.eclipse.smarthome.io.monitor.internal.EventLogger@699eab9': Java heap space
java.lang.OutOfMemoryError: Java heap space
at java.util.HashMap.resize(HashMap.java:704) ~[?:?]
at java.util.HashMap.putVal(HashMap.java:629) ~[?:?]
at java.util.HashMap.put(HashMap.java:612) ~[?:?]
at java.util.HashSet.add(HashSet.java:220) ~[?:?]
at org.apache.felix.eventadmin.impl.handler.EventHandlerTracker.checkHandlerAndAdd(EventHandlerTracker.java:272) ~[?:?]
at org.apache.felix.eventadmin.impl.handler.EventHandlerTracker.getHandlers(EventHandlerTracker.java:237) ~[?:?]
at org.apache.felix.eventadmin.impl.handler.EventAdminImpl.postEvent(EventAdminImpl.java:180) ~[?:?]
at org.apache.felix.eventadmin.impl.security.EventAdminSecurityDecorator.postEvent(EventAdminSecurityDecorator.java:79) ~[?:?]
at org.ops4j.pax.logging.internal.eventadmin.EventAdminTracker.deliver(EventAdminTracker.java:115) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.internal.eventadmin.EventAdminTracker.postEvent(EventAdminTracker.java:68) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.log4j2.internal.PaxLoggingServiceImpl.handleEvents(PaxLoggingServiceImpl.java:378) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog0(PaxLoggerImpl.java:153) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.doLog(PaxLoggerImpl.java:144) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.log4j2.internal.PaxLoggerImpl.inform(PaxLoggerImpl.java:176) ~[7:org.ops4j.pax.logging.pax-logging-log4j2:1.10.1]
at org.ops4j.pax.logging.internal.TrackingLogger.inform(TrackingLogger.java:86) ~[6:org.ops4j.pax.logging.pax-logging-api:1.10.1]
at org.ops4j.pax.logging.slf4j.Slf4jLogger.info(Slf4jLogger.java:495) ~[6:org.ops4j.pax.logging.pax-logging-api:1.10.1]
at org.eclipse.smarthome.io.monitor.internal.EventLogger.receive(EventLogger.java:53) ~[?:?]
at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
I tried a openhab-cli clean-cache before I started OpenHAB again, but I’m not sure if that helps. Any other suggestions?
Maybe the bugs are known issues and already fixed in 2.4.0? I’d update to that version and if the bugs are still there, put some more effort into it. E.g. by finding the cause of a OutOfMemoryError.