OpenHAB RWE Smarthome Binding

[thefox73]

Hallo,

ich habe dieses Problem seit langem nicht gehabt und das Binding ist wochenlang durchgelaufen bei mir. Der Logfile-Auszug passt eigentlich. Die Session läuft ab und ein neues Login wird initiiert, was auch als erfolgreich bestätigt wird. Ich erinnere mich aber, dass ich das irgendwann auch einmal hatte.

Folgender Vorschlag:
1. Bitte teste die neuste Version, die jetzt bei OpenHAB offiziell enthalten ist aus den nightly builds: https://openhab.ci.cloudbees.com/job/ope...ab.binding$org.openhab.binding.rwesmarthome/
2. Bitte aktiviere das DEBUG-logging für das RWE-Smarthome-Binding. Dazu bitte in der logback.xml folgendes im unteren Bereich einfügen: <logger name="org.openhab.binding.rwesmarthome" level="DEBUG" />

Falls es erneut auftritt, poste bitte wieder den Log-Auszug. Ist dieser auch nicht aussagekräftig, dann solltest Du es nochmal im Loglevel "TRACE" wiederholen. Bitte poste in beiden Fällen neben dem Logausschnitt zum Session-Ablauf auch den Ausschnitt, wenn Du eine Veränderung über RWE Smarthome bei OH nicht mitbekommst. Z.B. Lichtschalter drücken, aber OH-Status ändert sich nicht.

Danke!

Hallo Ollie,

zwischenzeitlich ist das Binding wieder ein paar mal ausgestiegen. Meiner Meinung nach immer nach dem reconnect einer abgelaufenen Session.
Mir ist aufgefallen, dass das Log dann jeweils unterschiedlich aussieht.

Hier ein ein Reconnect, bei dem das binding anschließend noch funktionierte.
Nach "Login successful" wurden die Items neu eingelesen.

2015-11-27 01:106.470 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Session expired!Logged out from Notifications. Reason:SessionExpired
2015-11-27 01:106.473 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Shutting down RWE Smarthome communicator
2015-11-27 01:106.476 [DEBUG] [.o.b.r.i.c.RWESmarthomeSession] - Destroying session...
2015-11-27 01:107.782 [INFO ] [.o.b.r.i.c.RWESmarthomeSession] - Session expired!
2015-11-27 01:107.786 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Starting RWE Smarthome communicator
2015-11-27 01:109.754 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Login successful.
2015-11-27 01:10:47.985 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Configuration refreshed: 743
2015-11-27 01:10:47.988 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Found GenericActuator_Value 4e9bcfba-35ec-4535-8fa8-14c528f1b1a6 (OPENHAB_ROLLO/EG_AUF_AB). Valid params: variable
2015-11-27 01:10:47.991 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Found GenericActuator_Value 96a21f0a-a5f5-44de-bc4e-39fa430ccd8c (HUE/Bloom SZ 30%). Valid params: variable
2015-11-27 01:10:47.993 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Found SwitchActuator 79877d79-9583-4530-941e-16fe17d3ea66 (TECHNIK KELLER/Zisternenpumpe). Valid params: switch
2015-11-27 01:10:47.996 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Found GenericActuator_Value d40d2681-0f54-4dd8-89d4-2f18b0ca69ae (ÃœBERGREIFEND/Alarm scharf). Valid params: variable
2015-11-27 01:10:47



Das ist in folgendem Fall nicht passiert. Hier passiert nach Login successful nichts mehr.
Und dann läuft das binding auch nicht mehr.

2015-11-25 18:47:43.628 [WARN ] [.impl.client.DefaultHttpClient] - Authentication error: Unable to respond to any of these challenges: {}
2015-11-25 18:47:43.632 [INFO ] [o.b.r.i.c.client.RWEHTTPClient] - 401 Unauthorized returned - Session expired!
2015-11-25 18:47:43.637 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Session expired!401 Unauthorized returned - Session expired!
2015-11-25 18:47:45.076 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Login successful.


Weiterer Unterschied:
Session expired!401 Unauthorized returned
Das "unauthorized" steht nur dann im Log, wenn die Items nach dem reconnect nicht mehr eingelesen werden.

Ist nur eine Vermutung, aber könnte das das Problem sein?
Ich werde den Loglevel mal auf Trace stellen und weiter beobachten.

Danke vorab

Hier ein DEBUG-Log.




2015-11-29 09:07:21.098 [ERROR] [.o.b.r.i.c.RWESmarthomeSession] - HttpHostConnectException
org.apache.http.conn.HttpHostConnectException: Connection to https://xxx.xxx.xxx.x refused
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:15 ~[na:na]
at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:150) ~[na:na]
at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:121) ~[na:na]
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:575) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:425) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:820) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:754) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:732) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.openhab.binding.rwesmarthome.internal.communicator.client.RWEHTTPClient.execute(RWEHTTPClient.java:57) ~[bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeSession.executeRequest(RWESmarthomeSession.java:239) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeSession.executeRequest(RWESmarthomeSession.java:212) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeCommunicator.getNotificationsRequest(RWESmarthomeCommunicator.java:544) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeCommunicator.getNotifications(RWESmarthomeCommunicator.java:519) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeCommunicator.poll(RWESmarthomeCommunicator.java:241) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.RWESmarthomeBinding.execute(RWESmarthomeBinding.java:15 [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.0.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.0.jar:na]
Caused by: java.net.ConnectException: Die Wartezeit für die Verbindung ist abgelaufen
at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.7.0_40]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java39) ~[na:1.7.0_40]
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200) ~[na:1.7.0_40]
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182) ~[na:1.7.0_40]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java92) ~[na:1.7.0_40]
at java.net.Socket.connect(Socket.java:579) ~[na:1.7.0_40]
at sun.security.ssl.SSLSocketImpl.connect(SSLSocketImpl.java:61 ~[na:1.7.0_40]
at org.openhab.binding.rwesmarthome.internal.communicator.util.EasySSLSocketFactory.connectSocket(EasySSLSocketFactory.java:92) ~[bundlefile:na]
at org.apache.http.conn.scheme.SchemeSocketFactoryAdaptor.connectSocket(SchemeSocketFactoryAdaptor.java:62) ~[org.apache.httpcomponents.httpclient_4.1.3.v201209201135.jar:4.1.3]
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:14 ~[na:na]
... 16 common frames omitted
2015-11-29 09:07:21.205 [DEBUG] [LogicalDeviceStatesXMLResponse] - Vorzeitiges Dateiende.
org.xml.sax.SAXParseException: Vorzeitiges Dateiende.
at com.sun.org.apache.xerces.internal.parsers.DOMParser.parse(DOMParser.java:256) ~[na:1.7.0_40]
at com.sun.org.apache.xerces.internal.jaxp.DocumentBuilderImpl.parse(DocumentBuilderImpl.java45) ~[na:1.7.0_40]
at javax.xml.parsers.DocumentBuilder.parse(DocumentBuilder.java:121) ~[na:1.7.0_40]
at org.openhab.binding.rwesmarthome.internal.communicator.xmlresponse.GetAllLogicalDeviceStatesXMLResponse.<init>(GetAllLogicalDeviceStatesXMLResponse.java:63) ~[bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeCommunicator.getNotifications(RWESmarthomeCommunicator.java:529) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.communicator.RWESmarthomeCommunicator.poll(RWESmarthomeCommunicator.java:241) [bundlefile:na]
at org.openhab.binding.rwesmarthome.internal.RWESmarthomeBinding.execute(RWESmarthomeBinding.java:15 [bundlefile:na]
at org.openhab.core.binding.AbstractActiveBinding$BindingActiveService.execute(AbstractActiveBinding.java:156) [org.openhab.core_1.7.0.jar:na]
at org.openhab.core.service.AbstractActiveService$RefreshThread.run(AbstractActiveService.java:173) [org.openhab.core_1.7.0.jar:na]
2015-11-29 09:07:25.202 [WARN ] [.impl.client.DefaultHttpClient] - Authentication error: Unable to respond to any of these challenges: {}
2015-11-29 09:07:25.205 [INFO ] [o.b.r.i.c.client.RWEHTTPClient] - 401 Unauthorized returned - Session expired!
2015-11-29 09:07:25.209 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Session expired!401 Unauthorized returned - Session expired!
2015-11-29 09:07:26.659 [INFO ] [r.i.c.RWESmarthomeCommunicator] - Login successful.