Update miniserver state does not work

Question

Update miniserver state does not work

Closed this issue 7 years ago · 17 comments

Shogun1978 commented 7 years ago

Hello,
the function "Updates of openHAB channel's state in runtime according to control's state changes on the Miniserver" does not work in my environment. Tested with classic UI and HABpanel. I can control Loxone devices, but the if I e.g. switch on a light via Loxone app or wall switch, the state is not updated in HABpanel/classic UI. Running openHAB2 with 2.2.0-SNAPSHOT release, Miniserver software V8.3.3.21.
Might I have done something wrong?
Greetings,
Harald
P.S. Tested in Safari (11.0 (12604.1.38.1.7)), Chrome (61.0.3163.100) and Firefox (56.0)

Answer 1 · 2017-11-02T20:36:59.000Z

Ok, can be closed. I changed the "Period between connection keep-alive messages" from standard 240 to 120 seconds. Since then, it works.

Answer 2 · 2017-11-04T17:31:59.000Z

Sorry, issue didn't went with the change of keep-alive setting. Still no refresh, when I reload the the dashboard.

Answer 3 · 2017-11-04T18:02:28.000Z

Hi @Shogun1978
Could you please give me more details:

what exact version of the openHAB2 and the binding (does the binding come from openHAB or is installed separately?)
when you restart the binding or openHAB, does it work fine at first and breaks later or is wrong from the beginning?
when the state is not updating, what is the Thing status of your miniserver?
could you enable debug logging as described here and send the logs?
Thanks

Answer 4 · 2017-11-04T18:10:06.000Z

Hi ppieczul,
regarding your questions:

it is the openHAB 2.2.0 Build #1072, I use the binding that comes with openHAB (configured all in the web UI / PaperUI. Everything is found what is presented by the Loxone MS.
yes, everything works fine. I now tested how long it takes till the states will not change: 3-4 minutes. When I restart openHAB2, openHAB hangs in the WebUI with "Please stand by while UIs are being installed. This can take several minutes." Everything just works fine after cleaning the cache with "rm -rf /var/lib/openhab2/cache/*"
Thing status is still online
I am away for a week (IBM conference in Prague), so I can just try to get next weekend
Thank you for this great binding and your support!
Best regards,
Shogun

Answer 5 · 2017-11-13T21:42:33.000Z

Hi ppieczul,
I made DEBUG and TRACE logs - but there is just an openhab.log, which is empty.
Any ideas? Because I have no clue what it could be... The last thing I could do is a complete reinstall.
One last idea: Openhab2 runs in a KVM/Qemu Guest (Proxmox). But it shouldn't be a problem, the Loxone Miniserver Thing is visible and shown as online.
Regards,
Shogun

Answer 6 · 2017-11-13T21:46:16.000Z

To me it looks like the openHAB installation destabilized itself. I suppose not related to the binding itself. Reinstallation should help. Pawel W dniu pon., 13.11.2017 o 22:42 Shogun1978 <notifications@github.com> napisał(a):

…

Hi ppieczul, I made DEBUG and TRACE logs - but there is just an openhab.log, which is empty. Any ideas? Because I have no clue what it could be... The last thing I could do is a complete reinstall. One last idea: Openhab2 runs in a KVM/Qemu Guest (Proxmox). But it shouldn't be a problem, the Loxone Miniserver Thing is visible and shown as online. Regards, Shogun — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AJx5fssoX-gqZOHL1M7DxIFwhlwnbfcSks5s2LfKgaJpZM4QOzBG> .

Answer 7 · 2017-11-13T22:09:59.000Z

I rolled back to the initial snapshot directly after setting up the basic Ubuntu system before any other software (Java, OpenHAB). I will send you feedback when I tested everything - I have feeling, where the error could come from. But I want to be sure.

Answer 8 · 2017-11-13T23:03:15.000Z

Ok, it was not the Java nor old 2.1.0 code... here are the log files after a fresh reinstall. All files are created in debug mode. I additionally try the same with trace mode.

audit.log
events.log
openhab.log

Answer 9 · 2017-11-13T23:16:27.000Z

So around midnight in these logs the trace level gets somehow enabled - did you enable it manually? This is immediately followed by some weird exceptions from the framework. Is this when the problem starts occurring? W dniu wt., 14.11.2017 o 00:03 Shogun1978 <notifications@github.com> napisał(a):

…

Ok, it was not the Java nor old 2.1.0 code... here are the log files after a fresh reinstall. All files are created in debug mode. I additionally try the same with trace mode. audit.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1468963/audit.log> events.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1468964/events.log> openhab.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1468965/openhab.log> — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AJx5fgryg_XTKKCi15Kvnrgl1VDIh0FMks5s2Mq0gaJpZM4QOzBG> .

Answer 10 · 2017-11-13T23:55:53.000Z

...and around that time more unexpected things happen: at 23:53 there is a state update received to a value of NaN and keep alive is sent one after another, like keep alive time was reset. Nothing unusual before that. I suppose this indicates the real beginning of the problem and NaN can be a result as well as a cause of this problem. There is a pretty intense amount of state updates coming from the Miniserver in your setup. I assume this is under normal conditions and we'd like to keep it that way. I would propose to narrow down the circumstances in which this problem occurs. The trace level may be not helpful yet. Could you please eliminate all possible interactions with the openHAB (like using the UI - operating the items or even having a browser with habpanel open), possibly one by one and observe the log file openhab.log for the exceptions flow, which indicate the problem occurred. In the example it lasted around 40 minutes. We'll see if it depends on the UI and catch some logs to see if there is a pattern. Thanks Pawel 2017-11-14 0:16 GMT+01:00 Pawel Pieczul <notifications@github.com>:

…

So around midnight in these logs the trace level gets somehow enabled - did you enable it manually? This is immediately followed by some weird exceptions from the framework. Is this when the problem starts occurring? W dniu wt., 14.11.2017 o 00:03 Shogun1978 ***@***.***> napisał(a): > Ok, it was not the Java nor old 2.1.0 code... here are the log files after > a fresh reinstall. All files are created in debug mode. I additionally try > the same with trace mode. > > audit.log > <https://github.com/ppieczul/org.openhab.binding.loxone/ files/1468963/audit.log> > events.log > <https://github.com/ppieczul/org.openhab.binding.loxone/ files/1468964/events.log> > openhab.log > <https://github.com/ppieczul/org.openhab.binding.loxone/ files/1468965/openhab.log> > > — > You are receiving this because you commented. > > > Reply to this email directly, view it on GitHub > <https://github.com/ppieczul/org.openhab.binding.loxone/ issues/1#issuecomment-344089107>, > or mute the thread > <https://github.com/notifications/unsubscribe-auth/AJx5fgryg_ XTKKCi15Kvnrgl1VDIh0FMks5s2Mq0gaJpZM4QOzBG> > . > — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#1 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AJx5foQoKRnBbLmwI2_MmmZyLfJJdjy2ks5s2M3MgaJpZM4QOzBG> .

Answer 11 · 2017-11-14T17:13:17.000Z

First question: the trace level was set manual, when the error came up again. I set the log level to trace and then restarted, so these must be the last fragment of the changed. The function did not work before the change to trace. Attached I have the log files set to trace level from last night till this morning. The GUI just uses two items, a living room dimmer and a living room light (switched). Everything else is not registered as an item. The GUI was not used since last night (laptop closed). Maybe the files give some information. Additionally, I can use another item, that is not updated very often like a kitchen room light we seldom use. Then I will run on log level debug for 40 minutes and see, what happens. I will send over the log files also. First: here are the trace level files:

events.log
openhab.log
openhab1.log
(openhab1.log was changed from openhab.log.1 for upload)

Answer 12 · 2017-11-14T19:36:30.000Z

This is good data. It shows the websocket link and the client code is operational, but the part of the code that consumes the parsed messages is dead. So the message queue grows until all memory is consumed and then the disaster from your previous logs happens. We are closer. We need that part of the traces from the start of the system, until only traces from LxWsClient are left and those from LxServer are no more appearing. In the old logs this is the moment when NaN value appears. Nevertheless, the first conclusion for me is to prevent the situation where the message queue grows indefinitely due to some bug in the code, I will add some code to handle it. Thanks for your help! 2017-11-14 18:13 GMT+01:00 Shogun1978 <notifications@github.com>:

…

First question: the trace level was set manual, when the error came up again. I set the log level to trace and then restarted, so these must be the last fragment of the changed. The function did not work before the change to trace. Attached I have the log files set to trace level from last night till this morning. The GUI just uses two items, a living room dimmer and a living room light (switched). Everything else is not registered as an item. The GUI was not used since last night (laptop closed). Maybe the files give some information. Additionally, I can use another item, that is not updated very often like a kitchen room light we seldom use. Then I will run on log level debug for 40 minutes and see, what happens. I will send over the log files also. First: here are the trace level files: events.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1471819/events.log> openhab.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1471821/openhab.log> openhab1.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1471826/openhab1.log> (openhab1.log was changed from openhab.log.1 for upload) — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AJx5fmAVosM-QktQtHvac5IilOM1WEMqks5s2cougaJpZM4QOzBG> .

Answer 13 · 2017-11-14T20:45:18.000Z

No need to thank me, I have to thank you! Here is the last log in DEBUG mode. If you want, I can restart the system and run everything in TRACE mode. Just give me sign.
events.log
openhab.log

Answer 14 · 2017-11-14T20:57:33.000Z

So we have again this: Taupunkt Gästezimmer update to value NaN - this means the number conversion failed, maybe this kills the server thread. Traces will help to reproduce this on my side. Also maybe there is some exception silently logged - could you log in to Karaf console <http://docs.openhab.org/administration/console.html> and run log:exception-display. Thanks Pawel 2017-11-14 21:45 GMT+01:00 Shogun1978 <notifications@github.com>:

…

No need to thank me, I have to thank you! Here is the last log in DEBUG mode. If you want, I can restart the system and run everything in TRACE mode. Just give me sign. events.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1472461/events.log> openhab.log <https://github.com/ppieczul/org.openhab.binding.loxone/files/1472462/openhab.log> — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#1 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AJx5fpuNR9Qt35sSzHNgYxGzUxKQBAlCks5s2fvfgaJpZM4QOzBG> .

Answer 15 · 2017-11-14T21:08:56.000Z

Ok, I see... this is "dew point guest room". The value is calculated from a temperature and humidity sensor (1-wire). This sensor is faulty and gives sometimes bad values which seems to deliver a non readable value in Loxone. The value is "-nan(ind)". Here the formula:
243,12*((17,62I1)/(243,12+I1)+LN(I2/100))/((17,62243,12)/(243,12+I1)-LN(I2/100))
So if the humidity value falls to 0 (due to a faulty value of the sensor), the calculation gives out -nan(ind). This is causing the error in the Loxone binding.
Sorry for the stress - I will set a validation to prevent this error in Loxone. It was not your code, it was a bad value.

Answer 16 · 2017-11-16T12:52:46.000Z

Cool, we have nailed it down! Thanks a lot. I will repro locally and add some code to prevent such severe consequences in case it happens.

Answer 17 · 2017-11-16T17:07:29.000Z

Perfect, thank you for the amazing support and fast response! I hope you continue this binding for future releases. For now I simple excluded the values for openHAB to avoid these errors at all. But great if I could find a possible error that could come up from faulty calculations in Loxone (in this case it was an error in layer 8 ;-) ). Thanks again and please provide is with more great extensions and programs!