Problem mit HM-Dis-EP-WM55 und STICKY_UNREACH


#1

Ich binde nun seit einiger Zeit ein HM-Dis-EP-WM55 in meine homegear+openHAB2 Umgebung ein. Nun zu folgendem Problem. Sobald das HM-Dis-EP einen Übertragungsfehler hat, wird STICKY_UNREACH gesetzt. Nach einem kurzen Moment wird UNREACH wieder auf false gesetzt. Das ist ja kein Problem. Allerdings kann das Gerät erst wieder angesprochen werden, wenn homegear neu gestartet wird. Zudem funktionieren ab diesem Moment auch keine HM-CC-RT-DN Heizventile mehr. Diese lassen sich ebenfalls erst wieder ansprechen, wenn homegear neu gestartet wird.

Hier sind die Logs einer Reproduktion. Das Display ist STICKY_UNREACH=true aber UNREACH=false und es sollte zumindest theoretisch erreichbar sein.
Ich sende nun nochmal Daten an das Display. Geht nicht. Danach regle ich die Temperatur am Thermostat. Geht leider auch nicht. Wie gesagt, ein Service Neustart von homegear heilt dann alles.

Hier das Ergebnis von queues info. Ein Löschen der Queue hilft nicht.

(Peer)> queues info
Number of Pending queues: 1
Queue 1:
  Number of packets: 4
  Packet 1 (Type: Packet): 1A22B011FD046D4BD22A8003020A128113850A128013850A120A0A
  Packet 2 (Type: Message): Type: 02
  Packet 3 (Type: Packet): 1423B011FD046D4BD22A800314C01CD01DE016F203
  Packet 4 (Type: Message): Type: 02

openHAB log:

 2017-02-16 17:00:57.435 [INFO ] [.smarthome.model.script.Display_Flur] - building new message
2017-02-16 17:00:57.514 [INFO ] [.smarthome.model.script.Display_Flur] - new submit received: 020A128113850A128013850A120A0A14C01CD01DE016F203
2017-02-16 17:00:57.520 [INFO ] [.smarthome.model.script.Display_Flur] - new submit scheduled
2017-02-16 17:00:59.029 [INFO ] [.smarthome.model.script.Display_Flur] - submitting: 020A128113850A128013850A120A0A14C01CD01DE016F203
2017-02-16 17:01:04.046 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1aa93bd' takes more than 5000ms.
2017-02-16 17:01:04.055 [WARN ] [ome.core.thing.internal.ThingManager] - Handler for thing 'homematic:HG-HM-Dis-EP-WM55:82cf380a:NExxxxxxxx' takes more than 5000ms for processing event
2017-02-16 17:01:04.173 [ERROR] [ematic.handler.HomematicThingHandler] - -100 No answer from device. (sending setValue()
NExxxxxxxx:3
SUBMIT
020A128113850A128013850A120A0A14C01CD01DE016F203
)
java.io.IOException: -100 No answer from device. (sending setValue()
NExxxxxxxx:3
SUBMIT
020A128113850A128013850A120A0A14C01CD01DE016F203
)
	at org.openhab.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:47)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:91)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:103)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:79)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.RpcClient.setDatapointValue(RpcClient.java:273)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway$1.execute(AbstractHomematicGateway.java:539)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:61)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:518)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:493)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.handler.HomematicThingHandler.handleCommand(HomematicThingHandler.java:175)[216:org.openhab.binding.homematic:2.0.0]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:372)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:179)[98:org.eclipse.smarthome.core:0.9.0.b4]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]
2017-02-16 17:01:17.648 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1aa93bd' takes more than 5000ms.
2017-02-16 17:01:17.648 [WARN ] [ome.core.thing.internal.ThingManager] - Handler for thing homematic:HG-HM-CC-RT-DN:82cf380a:MEQxxxxxxx takes more than 5000ms for processing event
2017-02-16 17:01:17.655 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1aa93bd' takes more than 5000ms.
2017-02-16 17:01:17.655 [WARN ] [ome.core.thing.internal.ThingManager] - Handler for thing 'homematic:HG-HM-CC-RT-DN:82cf380a:MEQxxxxxxx' takes more than 5000ms for processing event
2017-02-16 17:01:17.776 [ERROR] [ematic.handler.HomematicThingHandler] - -100 No answer from device. (sending setValue()
MEQxxxxxxx:4
SET_TEMPERATURE
20.5
)
java.io.IOException: -100 No answer from device. (sending setValue()
MEQxxxxxxx:4
SET_TEMPERATURE
20.5
)
	at org.openhab.binding.homematic.internal.communicator.parser.RpcResponseParser.parse(RpcResponseParser.java:47)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:91)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:103)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.BinRpcClient.sendMessage(BinRpcClient.java:79)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.client.RpcClient.setDatapointValue(RpcClient.java:273)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway$1.execute(AbstractHomematicGateway.java:539)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.misc.DelayedExecuter.start(DelayedExecuter.java:61)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:518)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.internal.communicator.AbstractHomematicGateway.sendDatapoint(AbstractHomematicGateway.java:493)[216:org.openhab.binding.homematic:2.0.0]
	at org.openhab.binding.homematic.handler.HomematicThingHandler.handleCommand(HomematicThingHandler.java:175)[216:org.openhab.binding.homematic:2.0.0]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:372)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
	at org.eclipse.smarthome.core.thing.internal.ThingManager$4.call(ThingManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.b4]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:179)[98:org.eclipse.smarthome.core:0.9.0.b4]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_65]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_65]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_65]

openHAB Events:

2017-02-16 17:00:57.385 [ItemCommandEvent          ] - Item 'Update_Display_Flur' received command OFF
2017-02-16 17:00:57.391 [ItemStateChangedEvent     ] - Update_Display_Flur changed from ON to OFF
2017-02-16 17:00:57.423 [ItemCommandEvent          ] - Item 'Dis_Flur_BuildMessage' received command ON
2017-02-16 17:00:57.506 [ItemCommandEvent          ] - Item 'Dis_Flur_SubmitFunc' received command 020A128113850A128013850A120A0A14C01CD01DE016F203
2017-02-16 17:01:04.049 [ItemCommandEvent          ] - Item 'Dis_Flur_Submit' received command 020A128113850A128013850A120A0A14C01CD01DE016F203
2017-02-16 17:01:10.584 [hingStatusInfoChangedEvent] - 'homematic:HG-HM-Dis-EP-WM55:82cf380a:NEQxxxxxx' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2017-02-16 17:01:10.601 [ItemStateChangedEvent     ] - Dis_Flur_Unreach changed from OFF to ON
2017-02-16 17:01:12.297 [hingStatusInfoChangedEvent] - 'homematic:HG-HM-Dis-EP-WM55:82cf380a:NEQxxxxxx' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
2017-02-16 17:01:12.351 [ItemStateChangedEvent     ] - Dis_Flur_Unreach changed from ON to OFF
2017-02-16 17:01:12.517 [ThingUpdatedEvent         ] - Thing 'homematic:HG-HM-Dis-EP-WM55:82cf380a:NEQxxxxxx' has been updated.
2017-02-16 17:01:17.655 [ItemCommandEvent          ] - Item 'SetTemp_Heiz_WohnZ' received command 20.5
2017-02-16 17:01:17.664 [ItemStateChangedEvent     ] - SetTemp_Heiz_WohnZ changed from 21.00 to 20.5
2017-02-16 17:01:24.182 [hingStatusInfoChangedEvent] - 'homematic:HG-HM-CC-RT-DN:82cf380a:MEQxxxxxxx' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2017-02-16 17:01:26.982 [hingStatusInfoChangedEvent] - 'homematic:HG-HM-CC-RT-DN:82cf380a:MEQxxxxxxx' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE
2017-02-16 17:01:27.140 [ItemStateChangedEvent     ] - SetTemp_Heiz_WohnZ changed from 20.5 to 21.00
2017-02-16 17:01:27.369 [ThingUpdatedEvent         ] - Thing 'homematic:HG-HM-CC-RT-DN:82cf380a:MEQxxxxxxx' has been updated.

homegear log:

02/16/17 17:00:58.583 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65353 accepted. Client number: 9200
02/16/17 17:00:58.584 RPC Server (Port 2001): Info: RPC server client id for client number 9200 is: 6269
02/16/17 17:00:58.584 RPC Server (Port 2001): Info: Client number 9200 is calling RPC method: getServiceMessages (2) Parameters:
02/16/17 17:00:58.705 RPC Server (Port 2001): Info: Connection to client number 9200 closed (3).
02/16/17 17:00:59.047 RPC Server (Port 2001): Info: Connection to client number 8671 closed (3).
02/16/17 17:00:59.049 RPC Server (Port 2001): Info: Connection from 127.0.0.1:53620 accepted. Client number: 9201
02/16/17 17:00:59.050 RPC Server (Port 2001): Info: RPC server client id for client number 9201 is: 6270
02/16/17 17:00:59.051 RPC Server (Port 2001): Info: Client number 9201 is calling RPC method: setValue (2) Parameters:
(String) NEQxxxxxx:3
(String) SUBMIT
(String) 020A128113850A128013850A120A0A14C01CD01DE016F203
02/16/17 17:00:59.052 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 1A20B011FD046D4BD22A8003020A128113850A128013850A120A0A
02/16/17 17:01:00.840 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65354 accepted. Client number: 9202
02/16/17 17:01:00.841 RPC Server (Port 2001): Info: RPC server client id for client number 9202 is: 6271
02/16/17 17:01:00.842 RPC Server (Port 2001): Info: Client number 9202 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:00.845 RPC Server (Port 2001): Info: Connection to client number 9202 closed (3).
02/16/17 17:01:01.074 HomeMatic BidCoS packet received (My-HM-MOD-RPI-PCB, RSSI: -73 dBm): 0F9E86103177970000000AA0CA091B00
02/16/17 17:01:01.075 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:01.075 Module HomeMatic BidCoS: Info: ACTUAL_TEMPERATURE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x00CA.
02/16/17 17:01:01.076 Module HomeMatic BidCoS: Info: BATTERY_STATE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x09.
02/16/17 17:01:01.076 Module HomeMatic BidCoS: Info: BOOST_STATE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x00.
02/16/17 17:01:01.076 Module HomeMatic BidCoS: Info: CONTROL_MODE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x00.
02/16/17 17:01:01.076 Module HomeMatic BidCoS: Info: FAULT_REPORTING on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x00.
02/16/17 17:01:01.077 Module HomeMatic BidCoS: Info: PARTY_START_TIME on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x00.
02/16/17 17:01:01.077 Module HomeMatic BidCoS: Info: SET_TEMPERATURE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x28.
02/16/17 17:01:01.077 Module HomeMatic BidCoS: Info: VALVE_STATE on channel 4 of HomeMatic BidCoS peer 5 with serial number LEQ0864289 was set to 0x1B.
02/16/17 17:01:01.081 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:01.610 RPC Server (Port 2001): Info: Connection to client number 9201 closed (3).
02/16/17 17:01:01.612 RPC Server (Port 2001): Info: Connection from 127.0.0.1:53626 accepted. Client number: 9205
02/16/17 17:01:01.612 RPC Server (Port 2001): Info: RPC server client id for client number 9205 is: 6272
02/16/17 17:01:01.614 RPC Server (Port 2001): Info: Client number 9205 is calling RPC method: setValue (2) Parameters:
(String) NEQxxxxxx:3
(String) SUBMIT
(String) 020A128113850A128013850A120A0A14C01CD01DE016F203
02/16/17 17:01:03.591 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65361 accepted. Client number: 9206
02/16/17 17:01:03.591 RPC Server (Port 2001): Info: RPC server client id for client number 9206 is: 6273
02/16/17 17:01:03.592 RPC Server (Port 2001): Info: Client number 9206 is calling RPC method: getServiceMessages (2) Parameters:
02/16/17 17:01:03.714 RPC Server (Port 2001): Info: Connection to client number 9206 closed (3).
02/16/17 17:01:04.180 RPC Server (Port 2001): Info: Client number 9205 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:04.262 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:04.263 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 42). Retrying...
02/16/17 17:01:04.363 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 1A22B011FD046D4BD22A8003020A128113850A128013850A120A0A
02/16/17 17:01:04.976 HomeMatic BidCoS packet received (My-HM-MOD-RPI-PCB, RSSI: -53 dBm): 0FBF86103F72A70000000AA0C90E0000
02/16/17 17:01:04.978 Module HomeMatic BidCoS: Info: ACTUAL_TEMPERATURE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00C9.
02/16/17 17:01:04.978 Module HomeMatic BidCoS: Info: BATTERY_STATE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x0E.
02/16/17 17:01:04.978 Module HomeMatic BidCoS: Info: BOOST_STATE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00.
02/16/17 17:01:04.978 Module HomeMatic BidCoS: Info: CONTROL_MODE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00.
02/16/17 17:01:04.979 Module HomeMatic BidCoS: Info: FAULT_REPORTING on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00.
02/16/17 17:01:04.979 Module HomeMatic BidCoS: Info: PARTY_START_TIME on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00.
02/16/17 17:01:04.979 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:04.979 Module HomeMatic BidCoS: Info: SET_TEMPERATURE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x28.
02/16/17 17:01:04.980 Module HomeMatic BidCoS: Info: VALVE_STATE on channel 4 of HomeMatic BidCoS peer 8 with serial number MEQ1580834 was set to 0x00.
02/16/17 17:01:04.986 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:05.846 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65362 accepted. Client number: 9209
02/16/17 17:01:05.846 RPC Server (Port 2001): Info: RPC server client id for client number 9209 is: 6274
02/16/17 17:01:05.847 RPC Server (Port 2001): Info: Client number 9209 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:05.850 RPC Server (Port 2001): Info: Connection to client number 9209 closed (3).
02/16/17 17:01:06.366 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:06.367 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 42). Retrying...
02/16/17 17:01:06.467 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 1A22B011FD046D4BD22A8003020A128113850A128013850A120A0A
02/16/17 17:01:07.836 HomeMatic BidCoS packet received (My-HM-MOD-RPI-PCB, RSSI: -57 dBm): 0CC486702C76F900000000C238
02/16/17 17:01:07.838 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:07.838 Module HomeMatic BidCoS: Info: HUMIDITY on channel 1 of HomeMatic BidCoS peer 20 with serial number LEQ0868055 was set to 0x38.
02/16/17 17:01:07.839 Module HomeMatic BidCoS: Info: TEMPERATURE on channel 1 of HomeMatic BidCoS peer 20 with serial number LEQ0868055 was set to 0x00C2.
02/16/17 17:01:07.843 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:08.470 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:08.471 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 42). Retrying...
02/16/17 17:01:08.571 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 1A22B011FD046D4BD22A8003020A128113850A128013850A120A0A
02/16/17 17:01:08.581 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65369 accepted. Client number: 9212
02/16/17 17:01:08.582 RPC Server (Port 2001): Info: RPC server client id for client number 9212 is: 6275
02/16/17 17:01:08.582 RPC Server (Port 2001): Info: Client number 9212 is calling RPC method: getServiceMessages (2) Parameters:
02/16/17 17:01:08.703 RPC Server (Port 2001): Info: Connection to client number 9212 closed (3).
02/16/17 17:01:10.574 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:10.575 Info: Peer 42 is unreachable.
02/16/17 17:01:10.575 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:10.851 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65370 accepted. Client number: 9214
02/16/17 17:01:10.851 RPC Server (Port 2001): Info: RPC server client id for client number 9214 is: 6276
02/16/17 17:01:10.852 RPC Server (Port 2001): Info: Client number 9214 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:10.855 RPC Server (Port 2001): Info: Connection to client number 9214 closed (3).
02/16/17 17:01:12.287 Info: Peer 42 is reachable again.
02/16/17 17:01:12.287 RPC client: Info: Calling RPC method "system.multicall" on server 192.168.178.21.
02/16/17 17:01:12.648 RPC Server (Port 2001): Info: Client number 9205 is calling RPC method: setValue (2) Parameters:
(String) MEQxxxxxxx:4
(String) SET_TEMPERATURE
(Float) 20.5
02/16/17 17:01:12.651 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 0C95B011FD046D3F72AF860429
02/16/17 17:01:13.584 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65377 accepted. Client number: 9216
02/16/17 17:01:13.584 RPC Server (Port 2001): Info: RPC server client id for client number 9216 is: 6277
02/16/17 17:01:13.585 RPC Server (Port 2001): Info: Client number 9216 is calling RPC method: getServiceMessages (2) Parameters:
02/16/17 17:01:13.706 RPC Server (Port 2001): Info: Connection to client number 9216 closed (3).
02/16/17 17:01:15.213 RPC Server (Port 2001): Info: Connection to client number 9205 closed (3).
02/16/17 17:01:15.214 RPC Server (Port 2001): Info: Connection from 127.0.0.1:53642 accepted. Client number: 9217
02/16/17 17:01:15.215 RPC Server (Port 2001): Info: RPC server client id for client number 9217 is: 6278
02/16/17 17:01:15.216 RPC Server (Port 2001): Info: Client number 9217 is calling RPC method: setValue (2) Parameters:
(String) MEQxxxxxxx:4
(String) SET_TEMPERATURE
(Float) 20.5
02/16/17 17:01:15.856 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65378 accepted. Client number: 9218
02/16/17 17:01:15.857 RPC Server (Port 2001): Info: RPC server client id for client number 9218 is: 6279
02/16/17 17:01:15.858 RPC Server (Port 2001): Info: Client number 9218 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:15.861 RPC Server (Port 2001): Info: Connection to client number 9218 closed (3).
02/16/17 17:01:17.860 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:17.861 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 1). Retrying...
02/16/17 17:01:17.961 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 0C96B011FD046D3F72AF860429
02/16/17 17:01:18.590 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65385 accepted. Client number: 9219
02/16/17 17:01:18.590 RPC Server (Port 2001): Info: RPC server client id for client number 9219 is: 6280
02/16/17 17:01:18.591 RPC Server (Port 2001): Info: Client number 9219 is calling RPC method: getServiceMessages (2) Parameters:
02/16/17 17:01:18.712 RPC Server (Port 2001): Info: Connection to client number 9219 closed (3).
02/16/17 17:01:19.188 RPC Server (Port 2001): Info: Client number 9217 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:19.964 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:19.964 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 1). Retrying...
02/16/17 17:01:20.064 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 0C96B011FD046D3F72AF860429
02/16/17 17:01:20.862 RPC Server (Port 2001): Info: Connection from 192.168.178.25:65386 accepted. Client number: 9220
02/16/17 17:01:20.862 RPC Server (Port 2001): Info: RPC server client id for client number 9220 is: 6281
02/16/17 17:01:20.863 RPC Server (Port 2001): Info: Client number 9220 is calling RPC method: listBidcosInterfaces (2) Parameters:
02/16/17 17:01:21.060 RPC Server (Port 2001): Info: Connection to client number 9220 closed (3).
02/16/17 17:01:22.068 Module HomeMatic BidCoS: Info: Setting peer to unreachable, because the queue processing was interrupted.
02/16/17 17:01:22.068 Module HomeMatic BidCoS: Info: Queue is not finished (peer: 1). Retrying...

Kann mir da wer helfen? Es ist übrigens egal, ob ich den SUBMIT per homegear fülle oder openHAB.


HM-CC-RT-DN - UPDATE_PENDING bleibt stehen
HM-Dis-WM55
#2

Hallo @lopez1de,

da scheint es ein Problem im Quelltext für den HM-MOD-RPI-PCB zu geben. Ich schaue mir das die Tage an. Mit anderen Kommunikationsmodulen besteht dieses Problem nicht.

Viele Grüße

Sathya


#3

Danke. Ich bin gespannt ob du was finden kannst.


#4

Ich habe den HM-MOD-RPI-PCB jetzt über viele Tage ohne Probleme getestet - der Fehler scheint also behoben ;-).


#5

Das klingt ja gut. Das heisst ich muss nun die nightlies installieren, damit der Fehler für mich auch evtl. behoben ist? Wenn ja, wie stellt man das denn an. Ich habe ja bereits die release version installiert.

Danke und Gruß


#6

:slight_smile:

Damit wir die aktuelle Nightly “über” die installierte Version installiert.


#7

Ich habe gerade aktualisiert auf 0.6.20-987 und frage mich ob eine Chance besteht, das dort der Fehler evtl. behoben ist. Würde prinzipiell gerne auf nightly verzichten.

Und falls ich doch auf die nightlies wechsele. Werden die auch mit “apt-get upgrade” aktualisiert?


#8

0.6.20-987 hat das Problem weiterhin.

Das Skript zum installieren der nightly funktioniert unter raspbian anscheinend nicht.

root@raspberrypi:~# wget -O - https://homegear.eu/downloads/InstallNightly.sh | bash
--2017-04-02 18:49:29--  https://homegear.eu/downloads/InstallNightly.sh
Auflösen des Hostnamen »homegear.eu (homegear.eu)«... 138.201.146.201, 2a01:4f8:172:19a5::3
Verbindungsaufbau zu homegear.eu (homegear.eu)|138.201.146.201|:443... verbunden.
HTTP-Anforderung gesendet, warte auf Antwort... 200 OK
Länge: 12613 (12K) [application/octet-stream]
In »»STDOUT«« speichern.

-                   100%[=====================>]  12,32K  --.-KB/s   in 0,002s

2017-04-02 18:49:29 (5,57 MB/s) - auf die Standardausgabe geschrieben [12613/12613]

Installing dependencies...
OK   http://archive.raspberrypi.org jessie InRelease
Holen: 1 http://mirrordirector.raspbian.org jessie InRelease [14,9 kB]
OK   https://homegear.eu jessie/ InRelease
Ign http://dl.bintray.com stable InRelease
Ign http://dl.bintray.com stable InRelease
Holen: 2 http://dl.bintray.com stable Release.gpg [821 B]
Holen: 3 http://dl.bintray.com stable Release.gpg [821 B]
Holen: 4 http://dl.bintray.com stable Release [6.050 B]
OK   http://archive.raspberrypi.org jessie/main armhf Packages
Holen: 5 http://dl.bintray.com stable Release [6.050 B]
Holen: 6 http://mirrordirector.raspbian.org jessie/main armhf Packages [8.981 kB]
OK   http://archive.raspberrypi.org jessie/ui armhf Packages
OK   https://homegear.eu jessie/ Packages
Holen: 7 https://homegear.eu jessie/ Translation-de_DE [232 B]
Holen: 8 https://homegear.eu jessie/ Translation-de [229 B]
Holen: 9 http://dl.bintray.com stable/main armhf Packages [77,8 kB]
Holen: 10 https://homegear.eu jessie/ Translation-en [229 B]
Holen: 11 https://homegear.eu jessie/ Translation-de_DE [232 B]
Holen: 12 https://homegear.eu jessie/ Translation-de [229 B]
Holen: 13 https://homegear.eu jessie/ Translation-en [229 B]
Holen: 14 https://homegear.eu jessie/ Translation-de_DE [232 B]
Holen: 15 https://homegear.eu jessie/ Translation-de [229 B]
Holen: 16 https://homegear.eu jessie/ Translation-en [229 B]
Holen: 17 https://homegear.eu jessie/ Translation-de_DE [232 B]
Holen: 18 https://homegear.eu jessie/ Translation-de [229 B]
Holen: 19 https://homegear.eu jessie/ Translation-en [229 B]
Holen: 20 https://homegear.eu jessie/ Translation-de_DE [232 B]
Ign https://homegear.eu jessie/ Translation-de_DE
Holen: 21 http://dl.bintray.com stable/main armhf Packages [666 B]
Holen: 22 https://homegear.eu jessie/ Translation-de [229 B]
Ign https://homegear.eu jessie/ Translation-de
Holen: 23 https://homegear.eu jessie/ Translation-en [229 B]
Ign https://homegear.eu jessie/ Translation-en
Ign http://dl.bintray.com stable/main Translation-de_DE
Ign http://dl.bintray.com stable/main Translation-de
Ign http://archive.raspberrypi.org jessie/main Translation-de_DE
Ign http://dl.bintray.com stable/main Translation-en
Ign http://dl.bintray.com stable/main Translation-de_DE
Ign http://archive.raspberrypi.org jessie/main Translation-de
Ign http://dl.bintray.com stable/main Translation-de
Ign http://archive.raspberrypi.org jessie/main Translation-en
Ign http://dl.bintray.com stable/main Translation-en
Ign http://archive.raspberrypi.org jessie/ui Translation-de_DE
Ign http://archive.raspberrypi.org jessie/ui Translation-de
Ign http://archive.raspberrypi.org jessie/ui Translation-en
Holen: 24 http://mirrordirector.raspbian.org jessie/contrib armhf Packages [37,5 kB]
Holen: 25 http://mirrordirector.raspbian.org jessie/non-free armhf Packages [70,3 kB]
Holen: 26 http://mirrordirector.raspbian.org jessie/rpi armhf Packages [1.356 B]
Ign http://mirrordirector.raspbian.org jessie/contrib Translation-de_DE
Ign http://mirrordirector.raspbian.org jessie/contrib Translation-de
Ign http://mirrordirector.raspbian.org jessie/contrib Translation-en
Ign http://mirrordirector.raspbian.org jessie/main Translation-de_DE
Ign http://mirrordirector.raspbian.org jessie/main Translation-de
Ign http://mirrordirector.raspbian.org jessie/main Translation-en
Ign http://mirrordirector.raspbian.org jessie/non-free Translation-de_DE
Ign http://mirrordirector.raspbian.org jessie/non-free Translation-de
Ign http://mirrordirector.raspbian.org jessie/non-free Translation-en
Ign http://mirrordirector.raspbian.org jessie/rpi Translation-de_DE
Ign http://mirrordirector.raspbian.org jessie/rpi Translation-de
Ign http://mirrordirector.raspbian.org jessie/rpi Translation-en
Es wurden 9.197 kB in 25 s geholt (364 kB/s).
Paketlisten werden gelesen... Fertig
Paketlisten werden gelesen... Fertig
Abhängigkeitsbaum wird aufgebaut.
Statusinformationen werden eingelesen.... Fertig
Die folgenden NEUEN Pakete werden installiert:
  dialog
0 aktualisiert, 1 neu installiert, 0 zu entfernen und 1 nicht aktualisiert.
Es müssen 233 kB an Archiven heruntergeladen werden.
Nach dieser Operation werden 750 kB Plattenplatz zusätzlich benutzt.
Holen: 1 http://mirrordirector.raspbian.org/raspbian/ jessie/main dialog armhf 1.2-20140911-1 [233 kB]
Es wurden 233 kB in 0 s geholt (374 kB/s).
Vormals nicht ausgewähltes Paket dialog wird gewählt.
(Lese Datenbank ... 33993 Dateien und Verzeichnisse sind derzeit installiert.)
Vorbereitung zum Entpacken von .../dialog_1.2-20140911-1_armhf.deb ...
Entpacken von dialog (1.2-20140911-1) ...
Trigger für man-db (2.7.0.2-5) werden verarbeitet ...
dialog (1.2-20140911-1) wird eingerichtet ...
stty: Standardeingabe: Unpassender IOCTL (I/O-Control) für das Gerät
stty: Standardeingabe: Unpassender IOCTL (I/O-Control) für das Gerät

Can't make new window at (14,14), size (-5,49).

EDIT: Das hier funktioniert:
wget -O /tmp/InstallNightly.sh https://homegear.eu/downloads/InstallNightly.sh && bash /tmp/InstallNightly.sh
Quelle: Homegear startet nicht nach update auf Nightly 0.7.0-1508


#9

Das Problem besteht auch noch mit version Homegear (version 0.7.0-1576).
Und ich denke es ist ein spezielles Problem mit dem HM-Dis-EP-WM55.


#10

Schade, dass die Nightly dein Problem nicht löst. Da muss @sathya was zu sagen.

Habe den Starterguide entsprechend angepasst.


#11

Hallo @lopez1de,

Und ich denke es ist ein spezielles Problem mit dem HM-Dis-EP-WM55.

Da stimme ich dir zu. Und zwar (vermutlich nur) in Verbindung mit dem HM-MOD-RPI-PCB. Ich vermute mal du hast die aktuelle Firmware auf dem Kommunikationsmodul? Es sieht so aus, als würden nach dem Senden des Paketes von dem HM-MOD-RPI-PCB keine Pakete mehr empfangen werden. Der Neustart von Homegear bewirkt auch einen Reset des Moduls, was erklärt, warum das das Problem löst. Ich werde bei mir mal testen, ob ich mit dem “SUBMIT”-Paket einen Absturz provozieren kann.

Viele Grüße

Sathya


#12

Ein firmware update des HM-MOD-RPI-PCB habe ich bisher nicht gemacht. Muss ich mal sehen wie das geht.

Anbei mein Testskript mit dem ich das Display “befeuer”.

 #!/usr/bin/env php
<?php
	include_once("Connect.php");
	
	while (true) {
		sleep(5);
		$result = $Client->send("setValue", array(42, 3, "SUBMIT", "020A128113850A128013850A1285330A0A14C01CD01DE016F203"));
		echo 'Result: '; var_dump($result);
	}
?>

#13

So. Firmwareupdate habe ich erledigt. Version ist nun theoretisch 1.4.1. Ich habe allerdings keine Ahnung welche Version ich vorher hatte.

Hilfreich waren dabei: HM-MOD-RPI-PCB und Raspberry2 Konfigurationsprobleme und https://heinz-otto.blogspot.de/2016/07/raspberry-pi-homematic-modul.html

Ich werde nun noch einmal testen.


#14

Das Problem besteht weiterhin. Auch wenn es gefühlt deutlich später in UNREACH geht.


#15

Auf Anhieb kann ich es bei mir nicht reproduzieren, allerdings habe ich kein HM-Dis-EP-WM55 zum Testen., so dass ich nur prüfen kann, ob nach einem nicht erfolgreichen Senden an ein HM-Dis-EP-WM55 Probleme auftreten.

Zudem funktionieren ab diesem Moment auch keine HM-CC-RT-DN Heizventile
mehr. Diese lassen sich ebenfalls erst wieder ansprechen, wenn homegear
neu gestartet wird.

Ist das denn noch der Fall? Oder lässt sich nur das HM-Dis-EP-WM55 nicht ansprechen?

Viele Grüße

Sathya


#16

Ich habe es nun mit einer aktuellen Homegear Version noch mal durchgespielt. Und das Problem besteht leider immer noch. Läuft das Display in einen Fehler lassen sich auch die Heizventile nicht mehr regeln.

Kann es denn sein das ich beim Testen in den DutyCycle rein laufe? Ich finde dafür allerdings kein Anzeichen in den Logs. Und nach einem Neustart von homegear läuft ja sofort alles wieder.

EDIT:
Ich sehe gerade, das Display wird nun in openhab2 direkt unterstützt. Ich werde diesen Weg versuchen und schauen ob die Probleme dort auch auftreten.


#17

Ja, die Probleme treten genauso auf.


#18

Hi @lopez1de,

Kann es denn sein das ich beim Testen in den DutyCycle rein laufe?

Ja, kann. Poste nochmal einen längeren Logabschnitt (Zeitfenster eine Stunde bis zum Problem), dann kann ich mal rechnen, ob das das Problem sein könnte.

Viele Grüße

Sathya


#19

Ich habe dir eine Nachricht geschickt.


#20

Hallo @lopez1de,

hab’s mir endlich angeschaut. Du erreichst in der aufgezeichneten Stunde etwa ein Drittel des Duty Cycles. Das ist also nicht das Problem. Was im Log auffällt ist, dass zum Fehlerzeitpunkt eine ganze Reihe von Paketen gesendet werden. Die Antworten kommen auch, nur viel zu spät. Z. B.:

10/24/17 14:07:25.635 Module HomeMatic BidCoS: HM-MOD-RPI-PCB "My-HM-MOD-RPI-PCB": Info: Sending (My-HM-MOD-RPI-PCB): 1AF0B011FD046D4BD22A8003020A12416E776573656E6413840A12
10/24/17 14:07:28.337 HomeMatic BidCoS packet received (My-HM-MOD-RPI-PCB, RSSI: -35 dBm): 0AF080024BD22AFD046D00

Ich würde das Problem zunächst einmal darauf schieben, dass der HM-MOD-RPI-PCB Probleme hat, so viele (WoR)-Anfragen gleichzeitig zu verarbeiten. Ich habe das Queue-Timeout jetzt mal auf 3 Sekunden erhöht. Schau mal, ob es jetzt besser klappt. Falls nicht, würde ich empfehlen, statt des HM-MOD-RPI-PCB einen CUL oder @pmayer s CC1101-Platine zu verwenden. Damit tritt das Problem nicht auf.

Viele Grüße

Sathya