Homematic IP timeout error ioBroker Visualisierung Win 10

[Wueli]

@wendy2702

2022-02-24 10:26:12.399 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 10:26:12.399 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 10:26:13.427 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 10:26:13.427 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 10:26:16.323 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 10:26:16.323 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 10:26:18.238 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 10:26:18.238 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 10:26:20.049 - info: plenticore.0 (16008) State value to set for "plenticore.0.scb.export.LastExportOk" has to be type "boolean" but received type "number"
2022-02-24 10:26:22.093 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 10:26:22.093 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 10:26:23.489 - error: hm-rpc.1 (5728) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 10:26:23.490 - error: hm-rpc.1 (5728) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)

Die CCU LOG ist extrem lang aber ich stell sie mal rein:

Feb 24 10:26:15 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:15 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:15 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:15 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:17 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:17 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:17 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:17 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: recvd 1535 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /rega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: recvd 1058 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /rega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:18 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 10:26:20 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: RX for OEQ1698160: @722306683 RSSI=-70dB 0x5F9F13 -> 0x000000 Generic [LEQ1010770]:   CNT=63,RPTEN=1,RPTED=0,BIDI=0,BURST=0,WAKEUP=0,WAKEMEUP=1,BCAST=1,TYPE=0x10   DATA = 0A A0 BB 0A 64 40 
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.CONTROL_MODE=1
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.FAULT_REPORTING=0
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.BATTERY_STATE=2.500000
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.VALVE_STATE=99
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.BOOST_STATE=0
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 4 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 4 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 4 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 4 events
Feb 24 10:26:21 homematic-ccu2 local0.info ReGaHss: Info: Event="OEQ1698160:4"."CONTROL_MODE"=1 [execute():iseXmlRpc.cpp:321]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7639 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7606 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: UpdateValue succeeded; val = 1 [execute():iseXmlRpc.cpp:364]
Feb 24 10:26:21 homematic-ccu2 local0.info ReGaHss: Info: Event="OEQ1698160:4"."FAULT_REPORTING"=0 [execute():iseXmlRpc.cpp:321]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7639 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7606 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: UpdateValue succeeded; val = 0 [execute():iseXmlRpc.cpp:364]
Feb 24 10:26:21 homematic-ccu2 local0.info ReGaHss: Info: Event="OEQ1698160:4"."BATTERY_STATE"=2.500000 [execute():iseXmlRpc.cpp:321]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7639 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7606 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: UpdateValue succeeded; val = 2.500000 [execute():iseXmlRpc.cpp:364]
Feb 24 10:26:21 homematic-ccu2 local0.info ReGaHss: Info: Event="OEQ1698160:4"."VALVE_STATE"=99 [execute():iseXmlRpc.cpp:321]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7639 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7606 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: UpdateValue succeeded; val = 99 [execute():iseXmlRpc.cpp:364]
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: type = DP_EXACTVALUE, condition valL = 1 valR1 = 0 [Evaluate():iseCondition.cpp:352]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: sc = 0, condition result = 0 [Evaluate():iseCondition.cpp:1123]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: type = DP_EXACTVALUE, condition valL = 2 valR1 = 0 [Evaluate():iseCondition.cpp:352]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: sc = 0, condition result = 0 [Evaluate():iseCondition.cpp:1123]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.ACTUAL_TEMPERATURE=18.700000
Feb 24 10:26:21 homematic-ccu2 local0.info ReGaHss: Info: Event="OEQ1698160:4"."BOOST_STATE"=0 [execute():iseXmlRpc.cpp:321]
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7639 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: Event: OEQ1698160:4.SET_TEMPERATURE=20.000000
Feb 24 10:26:21 homematic-ccu2 local0.debug ReGaHss: Verbose: call on change; id = 7606 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 10:26:21 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed

MOD EDIT: LOG in Code Tags gesetzt

[wendy2702]

@wueli Kann m CCU log nichts ankommen sehen.

Kannst du das loggen für RPC auf Debug stellen:

Das loggen auf der CCU so:

Dann mal schalten, Uhrzeit merken und im Anschluß beide logs posten.

[Homoran]

@wendy2702 sagte in Homematic IP timeout error ioBroker Visualisierung:

wenn ich nicht täusche ist das Protokoll immer XML-RPC, egal ob RF oder IP.

@Wueli
Ja! nur noch CuxD verwendet BIN

Aber mich wundert, dass es ausgerechnet mit HM funktioniert. Dort ist es falsch

gib auch mal deine Callback-Adresse ein
Mich wundert der CCU-Log, da steht gar nicht wer anfragt

[Wueli]

@wendy2702

2022-02-24 11:14:49.582 - debug: hm-rpc.1 (8068) [KEEPALIVE] Check if connection is alive
2022-02-24 11:14:49.583 - debug: hm-rpc.1 (8068) Send PING...
2022-02-24 11:14:49.630 - debug: hm-rpc.1 (8068) PING ok
2022-02-24 11:14:49.716 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","CENTRAL:0","PONG","iobrokerserver(Wueli):hm-rpc.1"]
2022-02-24 11:14:49.716 - debug: hm-rpc.1 (8068) xmlrpc <- event: hm-rpc.1.CENTRAL.0.PONG:iobrokerserver(Wueli):hm-rpc.1 discarded, no matching device
2022-02-24 11:14:50.881 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: true
2022-02-24 11:14:50.881 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:51.614 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:51.615 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:14:51.646 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:14:51.646 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:14:53.345 - info: plenticore.0 (16008) State value to set for "plenticore.0.scb.export.LastExportOk" has to be type "boolean" but received type "number"
2022-02-24 11:14:53.493 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: false
2022-02-24 11:14:53.493 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:14:54.153 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:14:54.153 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:14:54.175 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:14:54.175 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:14:54.896 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: true
2022-02-24 11:14:54.896 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:55.429 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:55.430 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:14:55.441 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:14:55.442 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:14:56.819 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: false
2022-02-24 11:14:56.819 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:14:57.461 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:14:57.461 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:14:57.555 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:14:57.555 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:14:58.313 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: true
2022-02-24 11:14:58.313 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:58.947 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",true] BOOL
2022-02-24 11:14:58.947 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:14:58.962 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:14:58.962 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:15:05.682 - debug: hm-rpc.1 (8068) xmlrpc -> setValue 4 STATE: false
2022-02-24 11:15:05.683 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:15:06.453 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL
2022-02-24 11:15:06.453 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
2022-02-24 11:15:06.500 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]
2022-02-24 11:15:06.501 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"

Feb 24 11:14:47 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: recvd 1535 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /rega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: recvd 1058 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /rega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:49 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:50 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: Event: CENTRAL.PONG="iobrokerserver(Wueli):hm-rpc.0"
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send 1 events
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 11:14:51 homematic-ccu2 local0.info ReGaHss: Info: Event="CENTRAL"."PONG"="iobrokerserver(Wueli):hm-rpc.0" [execute():iseXmlRpc.cpp:321]
Feb 24 11:14:51 homematic-ccu2 local0.info ReGaHss: Info: PONG event 'CENTRAL' received. [execute():iseXmlRpc.cpp:335]
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 11:14:51 homematic-ccu2 user.debug rfd: HSSXmlRpcEventDispatcher::Handle send completed
Feb 24 11:14:53 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:53 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:53 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:53 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:55 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:55 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:55 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:55 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:56 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:56 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:56 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:56 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:14:59 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:14:59 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:14:59 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:14:59 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:00 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:00 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:00 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:00 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:02 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:02 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:02 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:02 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:04 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:04 homematic-ccu2 local0.info ReGaHss: Info: recvd 62 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:04 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:04 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:05 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:08 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:08 homematic-ccu2 local0.info ReGaHss: Info: recvd 747 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:15:08 homematic-ccu2 local0.info ReGaHss: Info: IseSession GetSessionId from URL: /esp/system.htm?sid=@2F0MH26Wo1@&action=UpdateUI [GetSessionId():iseSession.cpp:185]
Feb 24 11:15:08 homematic-ccu2 local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:15:10 homematic-ccu2 local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:15:10 homematic-ccu2 local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]

Habe mal die ZEit der CCU synchronisiert damit man vernünftig vergleichen kann.
War mir leider gerade erst aufgefallen.

[Wueli]

@homoran

Wie müsste die Callback Adresse lauten? Ist das die gleiche IP Adresse wie von der CCU?

Sorry wenn ich so viel Frage aber so tief stecke ich leider in der Materie nicht drin.

[Homoran]

@wueli sagte in Homematic IP timeout error ioBroker Visualisierung:

Ist das die gleiche IP Adresse wie von der CCU?

nein, die vom ioBroker

Da läuft doch hoffentlich nichts absonderliches wie Docker oder Container?

[Wueli]

@homoran said in Homematic IP timeout error ioBroker Visualisierung:

@wueli sagte in Homematic IP timeout error ioBroker Visualisierung:

Ist das die gleiche IP Adresse wie von der CCU?

nein, die vom ioBroker

Da läuft doch hoffentlich nichts absonderliches wie Docker oder Container?

Nein läuft nicht. Ist eine direkte Installation auf dem laufenden Windows 10

[Homoran]

@wueli sagte in Homematic IP timeout error ioBroker Visualisierung:

Ist eine direkte Installation auf dem laufenden Windows 10

dann bin ich leider raus
Mit WIN-Installationen kenne ich mich nicht aus.
Ob da die WIN-Firewall oder sonst etwas WIN spezifisches reinpfuscht, kann ich dir nicht beantworten

Solche Informationen gehören in den ersten Post, besser sogar in den Threadtitel

[Wueli]

@homoran said in Homematic IP timeout error ioBroker Visualisierung:

@wueli sagte in Homematic IP timeout error ioBroker Visualisierung:

Ist eine direkte Installation auf dem laufenden Windows 10

dann bin ich leider raus
Mit WIN-Installationen kenne ich mich nicht aus.
Ob da die WIN-Firewall oder sonst etwas WIN spezifisches reinpfuscht, kann ich dir nicht beantworten

Solche Informationen gehören in den ersten Post, besser sogar in den Threadtitel

Ok. Habe den Titel angepasst. Trotzdem Danke für die bisherige Hilfe.

[Wueli]

@homoran said in Homematic IP timeout error ioBroker Visualisierung:

Ob da die WIN-Firewall oder sonst etwas WIN spezifisches reinpfuscht, kann ich dir nicht beantworten

Wenn die Firewall das machen würde, müsste es ja jedes mal geblockt werden. Aber das ist nur eine Vermutung meinerseits.

[wendy2702]

@wueli sagte in Homematic IP timeout error ioBroker Visualisierung:

laufenden Windows 10

Die Info wäre direkt zu Beginn auch interessant gewesen.

Laut iobroker log ist das device nicht erreichbar

2022-02-24 11:14:53.493 - debug: hm-rpc.1 (8068) setValue ["00085D899C13AF:4","STATE",false] BOOL

2022-02-24 11:14:54.153 - error: hm-rpc.1 (8068) xmlrpc -> setValue ["00085D899C13AF:4","STATE",false] BOOL

2022-02-24 11:14:54.153 - error: hm-rpc.1 (8068) Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)

2022-02-24 11:14:54.175 - debug: hm-rpc.1 (8068) xmlrpc <- event ["iobrokerserver(Wueli):hm-rpc.1","00085D899C13AF:0","UNREACH",true]

2022-02-24 11:14:54.175 - debug: hm-rpc.1 (8068) hm-rpc.1.00085D899C13AF.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"

habe das mal bei mir nachgestellt. Habe allerdings nur die virtuellen HM-IP Devices. In VIS mal einen Taster angelegt. Wenn ich den betätige kommt das im RPC log:

2022-02-24 11:51:28.490  - debug: hm-rpc.2 (2492) setValue ["HmIP-RCV-1:1","PRESS_SHORT",false] ACTION
2022-02-24 11:51:28.518  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","HmIP-RCV-1:1","PRESS_SHORT",false]
2022-02-24 11:51:28.518  - debug: hm-rpc.2 (2492) hm-rpc.2.HmIP-RCV-1.1.PRESS_SHORT ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:29.503  - debug: hm-rpc.2 (2492) xmlrpc -> setValue 1 PRESS_SHORT: false
2022-02-24 11:51:29.503  - debug: hm-rpc.2 (2492) setValue ["HmIP-RCV-1:1","PRESS_SHORT",false] ACTION
2022-02-24 11:51:29.540  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","HmIP-RCV-1:1","PRESS_SHORT",false]
2022-02-24 11:51:29.541  - debug: hm-rpc.2 (2492) hm-rpc.2.HmIP-RCV-1.1.PRESS_SHORT ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:30.967  - debug: hm-rpc.2 (2492) xmlrpc -> setValue 1 PRESS_SHORT: true
2022-02-24 11:51:30.967  - debug: hm-rpc.2 (2492) setValue ["HmIP-RCV-1:1","PRESS_SHORT",true] ACTION
2022-02-24 11:51:30.991  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","HmIP-RCV-1:1","PRESS_SHORT",true]
2022-02-24 11:51:30.991  - debug: hm-rpc.2 (2492) hm-rpc.2.HmIP-RCV-1.1.PRESS_SHORT ==> UNIT: "undefined" (min: false, max: true) From "true" => "true"
2022-02-24 11:51:31.967  - debug: hm-rpc.2 (2492) xmlrpc -> setValue 1 PRESS_SHORT: false
2022-02-24 11:51:31.968  - debug: hm-rpc.2 (2492) setValue ["HmIP-RCV-1:1","PRESS_SHORT",false] ACTION
2022-02-24 11:51:31.982  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","HmIP-RCV-1:1","PRESS_SHORT",false]
2022-02-24 11:51:31.982  - debug: hm-rpc.2 (2492) hm-rpc.2.HmIP-RCV-1.1.PRESS_SHORT ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:33.853  - debug: hm-rpc.2 (2492) xmlrpc -> setValue 1 PRESS_SHORT: false
2022-02-24 11:51:33.853  - debug: hm-rpc.2 (2492) setValue ["HmIP-RCV-1:1","PRESS_SHORT",false] ACTION
2022-02-24 11:51:33.880  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","HmIP-RCV-1:1","PRESS_SHORT",false]
2022-02-24 11:51:33.880  - debug: hm-rpc.2 (2492) hm-rpc.2.HmIP-RCV-1.1.PRESS_SHORT ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:39.739  - debug: hm-rpc.2 (2492) xml multicall <event>: iobroker:hm-rpc.2,0010DD8989876F:0,CONFIG_PENDING,false
2022-02-24 11:51:39.739  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","0010DD8989876F:0","CONFIG_PENDING",false]
2022-02-24 11:51:39.739  - debug: hm-rpc.2 (2492) hm-rpc.2.0010DD8989876F.0.CONFIG_PENDING ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:39.739  - debug: hm-rpc.2 (2492) xml multicall <event>: iobroker:hm-rpc.2,0010DD8989876F:0,DUTY_CYCLE,false
2022-02-24 11:51:39.739  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","0010DD8989876F:0","DUTY_CYCLE",false]
2022-02-24 11:51:39.740  - debug: hm-rpc.2 (2492) hm-rpc.2.0010DD8989876F.0.DUTY_CYCLE ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:39.740  - debug: hm-rpc.2 (2492) xml multicall <event>: iobroker:hm-rpc.2,0010DD8989876F:0,LOW_BAT,false
2022-02-24 11:51:39.740  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","0010DD8989876F:0","LOW_BAT",false]
2022-02-24 11:51:39.741  - debug: hm-rpc.2 (2492) hm-rpc.2.0010DD8989876F.0.LOW_BAT ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"
2022-02-24 11:51:39.741  - debug: hm-rpc.2 (2492) xml multicall <event>: iobroker:hm-rpc.2,0010DD8989876F:0,UNREACH,false
2022-02-24 11:51:39.741  - debug: hm-rpc.2 (2492) xmlrpc <- event ["iobroker:hm-rpc.2","0010DD8989876F:0","UNREACH",false]
2022-02-24 11:51:39.741  - debug: hm-rpc.2 (2492) hm-rpc.2.0010DD8989876F.0.UNREACH ==> UNIT: "undefined" (min: false, max: true) From "false" => "false"

passend dazu im CCU log

Feb 24 11:51:30 ccu3-webui local0.info ReGaHss: Info: Event="HmIP-RCV-1:1"."PRESS_SHORT"=true [execute():iseXmlRpc.cpp:321]
Feb 24 11:51:30 ccu3-webui local0.debug ReGaHss: Verbose: call on change; id = 27367 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 11:51:30 ccu3-webui local0.debug ReGaHss: Verbose: call on change; id = 27365 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 11:51:30 ccu3-webui local0.debug ReGaHss: Verbose: call on change; id = 27367 [SetLastDPActionTime():iseDOMchn.h:288]
Feb 24 11:51:30 ccu3-webui local0.debug ReGaHss: Verbose: call on change; id = 27365 [SetLastActionTime():iseDOMdev.h:225]
Feb 24 11:51:30 ccu3-webui local0.debug ReGaHss: Verbose: UpdateValue succeeded; val = 1 [execute():iseXmlRpc.cpp:364]
Feb 24 11:51:31 ccu3-webui local0.debug ReGaHss: Verbose: wait max timeout = 240000 [ThreadFunction():iseRTEvent.cpp:69]
Feb 24 11:51:31 ccu3-webui local0.info ReGaHss: Info: start web processing, worker thread #0 {"HTTP-Listener"} [spawnNewProcess():httpListener.cpp:208]
Feb 24 11:51:31 ccu3-webui local0.info ReGaHss: Info: recvd 326 bytes by web server #1 [ThreadFunction():httpServer.cpp:771]
Feb 24 11:51:31 ccu3-webui local0.info ReGaHss: Info: IseSession GetSessionId from URL: /tclrega.exe [GetSessionId():iseSession.cpp:185]
Feb 24 11:51:31 ccu3-webui local0.info ReGaHss: Info: http id #1 sends parsed file [ParseFileAndSendWebResponse():httpServer.cpp:2035]
Feb 24 11:51:31 ccu3-webui local0.info ReGaHss: Info: Event="HmIP-RCV-1:1"."PRESS_SHORT"=false [execute():iseXmlRpc.cpp:321]

Davon sehe ich bei dir leider nichts. Entweder kommt es nicht an oder dein logging in der CCU steht nicht richtig

[Homoran]

@wendy2702 sagte in Homematic IP timeout error ioBroker Visualisierung Win 10:

Entweder kommt es nicht an

das befürchte ich - deswegen wahrscheinlich auch der Timeout

[wendy2702]

Wenn es ein WIN10 rechner ist.

Installiere Wireshark und starte einen Paket Mitschnitt auf dem interface. Dann kannst du sehen was iobroker an die CCU sendet und ob von dort irgendetwas zurück kommt.

[Wueli]

@wendy2702

Ok werde ich mal versuchen.
Hatte schon überlegt den Adapter einfach mal zu deinstallieren und wieder neu zu installieren. Der andere HM-RPC Adapter funktioniert ja tadellos.

[wendy2702]

@wueli Kann man natürlich auch mal probieren. Glaube aber nur eingeschränkt an Erfolg.

Da es aber kein großer Aufwand ist... Versuch macht klug.

[D3ltoroxp]

Ich hänge mich mal hier mit an. Ich mache zwar nichts mit der Visualisierung, aber auch ich habe Timeout Meldungen im Log. Manchmal schalten die Geräte manchmal nicht.

Folgendes taucht immer wieder mal in der Log auf.

hm-rpc.0
	2022-03-06 08:35:09.607	error	Cannot call setValue: XML-RPC fault: Generic error (TIMEOUT)
hm-rpc.0
	2022-03-06 08:35:09.607	error	xmlrpc -> setValue ["000A1A49A7C3E9:1","SET_POINT_TEMPERATURE",20] FLOAT

Ich habe sonst keine neuen Geräte dazu genommen und früher ist mir das auch so nicht aufgefallen, weder im Betrieb noch in der Log.

Wenn ich das bei dem betroffenen Geräte manuell über den DP im ioB steuere, setzt er den Wert sofort. Bei mir sind es fast nur HM IP Thermostate. Ich habe gerade bei allen möglichen hintereinander die Temp gewechselt, ohne Probleme und Fehlermeldung.