ioBroker.hm-rpc icon indicating copy to clipboard operation
ioBroker.hm-rpc copied to clipboard

Published 20 hours ago • verified publisher icon ioBroker

Tons of hm-rpc errors after performing a fw-update on any HmIP device

Open captaindork opened this issue 1 year ago • 10 comments

Describe the bug I am running hm-rpc for HmIP / XML-RPC and after updating the fw of any HmIP device, devices do not update or cannot be controlled (several, if not even -> all devices. At least far not only the updated Device). Basically the objects get deleted… In iobroker logs I can see a ton often following messages: „obsolete channel 000Bxxxxxxx „000Bxxxxxxx“ deleted“ „obsolete device 000Bxxxxxxx deleted“ followed by: „STATE „hm-rpc.2.000Bxxxxxxx.HUMIDITY“ has no existing object, this might lead to an error in future versions“ Can be fixed by a manual full resync of the devices in hm-rpc.

To Reproduce Steps to reproduce the behavior:

  1. Go to CCU and install a FW Update of any HmIP device, while connected to iobroker with XML-RPC
  2. As soon as the update has finished uploading to the device (OTA) an update button appears on the device.
  3. Click the Update button for a device with possible update
  4. as soon as the device performs the update (on battery powered devices, this might happen later after the device contacts the CCU next, or with a contact sensor for example you can enforce the update by open/closing the contact) iobroker hm-rpc will start deleting the objects (not sure, maybe even all adapter objects)
  5. Try to control an actor via iobroker -> will fail…
  6. Look at iobroker log -> it will look flooded with the errors mentioned above
  7. Go to settings of hm-rpc instance and tick box to sync devices from scratch + save&close
  8. After this all warnings will disappear again, objects will be created again and after full resync is done devices will work as normal in iobroker

Expected behavior hm-rpc adapter should continue to run normal even if a fw-update for a device is performed. I have more than 100 devices so it is very annoying to be required to perform a full resync after „each single update“ that is performed on any of the devices.

Screenshots & Logfiles Log entries named above

Versions:

  • hm-rpc version: 1.15.16
  • hm-rega version: 3.0.46
  • JS-Controller version: 4.0.24
  • Node version: 18.16.0
  • Operating system: linux
  • CCU model: CCU3
  • CCU firmware: 3.69.7

Additional context iobroker runs dockerized

captaindork avatar Apr 30 '23 16:04 captaindork

Log of the actual update procedure would be helpful to see what CCU actual sends in these updates that lead to the deletion. So we can delay the deletion to the point where the device finally has finished the update.

foxriver76 avatar Apr 30 '23 17:04 foxriver76

Hi! thx, you are referring to the logs from iobroker side?

2023-04-30 17:44:29.460 - [32minfo[39m: javascript.0 (286) script.js.CPT.Locks.Cabinet-Lock: clearTimeout() => cleared 2023-04-30 17:44:45.869 - [32minfo[39m: hm-rpc.2 (3759932) xmlrpc <- newDevices 4 2023-04-30 17:44:46.008 - [32minfo[39m: hm-rpc.2 (3759932) obsolete device 0000D3C996XXXX deleted 2023-04-30 17:44:46.009 - [32minfo[39m: hm-rpc.2 (3759932) obsolete channel 0000D3C996XXXX.0 "0000D3C996XXXX.0" deleted 2023-04-30 17:44:46.009 - [32minfo[39m: hm-rpc.2 (3759932) obsolete channel 0000D3C996XXXX.1 "0000D3C996XXXX.1" deleted

the javascript one on top is not related. Just wanted to show this are the first messages of hm-rpc. So what I can see it tells there are 4 new devices? And then the „deletion-run“ starts? I only updated one device in exactly this timeframe. I updated another single one earlier this day, same messages basically…

EDIT: Well actually the first javascript line is somewhat related… it’s the timestamp when I changed state of the „to be updated“ contact sensor which triggers a script cancelling a timeout, so I forced the device to update at exactly this point.

captaindork avatar Apr 30 '23 18:04 captaindork

I however have one device left for update (probably tomorrow). I will set loglevel of hm-rpc to detailed before I hit the update button then…

captaindork avatar Apr 30 '23 19:04 captaindork

Any news from the device left on debug loglevel?

foxriver76 avatar May 05 '23 06:05 foxriver76

Okay, I have some updates too, currently transmitting to the devices, until now no problems. I guess the problem occurs on install then. So I have to wait some hours

foxriver76 avatar May 05 '23 07:05 foxriver76

Hi,

yep sorry i got sick in between, so this introduced some delay. I did capture the logs one day later. Hopefully it contains no sensitive information :) This time it tells 9 New Devices, while i just updated one single device, not sure where the 9 comes from.

So it happens on install of the upgrade and in this case the upgraded device ended with 1C5F

2023-05-01 18:01:11.966 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,000E5709A11C5F:0,CONFIG_PENDING,false 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","000E5709A11C5F:0","CONFIG_PENDING",false] 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.000E5709A11C5F.0.CONFIG_PENDING ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,000E5709A11C5F:0,UNREACH,false 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","000E5709A11C5F:0","UNREACH",false] 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.000E5709A11C5F.0.UNREACH ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,000E5709A11C5F:0,RSSI_DEVICE,-90 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","000E5709A11C5F:0","RSSI_DEVICE",-90] 2023-05-01 18:01:11.967 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.000E5709A11C5F.0.RSSI_DEVICE ==> UNIT: "undefined" (min: -128, max: 127) From "-90" => "-90" 2023-05-01 18:01:11.969 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.000E5709A11C5F.0.CONFIG_PENDING:{"val":false,"ack":true,"ts":1682956871968,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869492096} 2023-05-01 18:01:11.969 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.000E5709A11C5F.0.UNREACH:{"val":false,"ack":true,"ts":1682956871968,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869492140} 2023-05-01 18:01:11.970 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.000E5709A11C5F.0.RSSI_DEVICE:{"val":-90,"ack":true,"ts":1682956871968,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682948566156} 2023-05-01 18:01:11.971 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12783).State(12698.8132) 2023-05-01 18:01:11.980 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:12.030 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12773).State(57) 2023-05-01 18:01:12.038 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:12.089 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12776).State(5.458000000000538) 2023-05-01 18:01:12.096 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:15.451 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12784:{"val":13996.7438,"ack":false,"ts":1682956875449,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875449} 2023-05-01 18:01:15.451 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12784 {"val":13996.7438,"ack":false,"ts":1682956875449,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875449} 2023-05-01 18:01:15.451 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12784: 13996.7438 2023-05-01 18:01:15.451 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12784).State(13996.7438) 2023-05-01 18:01:15.459 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:15.463 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12778:{"val":9.545099999999366,"ack":false,"ts":1682956875451,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875451} 2023-05-01 18:01:15.464 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12778 {"val":9.545099999999366,"ack":false,"ts":1682956875451,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875451} 2023-05-01 18:01:15.464 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12778: 9.545099999999366 2023-05-01 18:01:15.464 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12778).State(9.545099999999366) 2023-05-01 18:01:15.465 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12780:{"val":678,"ack":false,"ts":1682956875462,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875462} 2023-05-01 18:01:15.466 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12780 {"val":678,"ack":false,"ts":1682956875462,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956875462} 2023-05-01 18:01:15.466 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12780: 678 2023-05-01 18:01:15.466 - [34mdebug[39m: hm-rega.0 (1062892) 2 pending requests 2023-05-01 18:01:15.472 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:15.523 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12780).State(678) 2023-05-01 18:01:15.532 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:22.446 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,CONFIG_PENDING,false 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","CONFIG_PENDING",false] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.CONFIG_PENDING ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,DUTY_CYCLE,false 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","DUTY_CYCLE",false] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.DUTY_CYCLE ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,LOW_BAT,true 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","LOW_BAT",true] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.LOW_BAT ==> UNIT: "undefined" (min: undefined, max: undefined) From "true" => "true" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,UNREACH,false 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","UNREACH",false] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.UNREACH ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,RSSI_DEVICE,-52 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","RSSI_DEVICE",-52] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.RSSI_DEVICE ==> UNIT: "undefined" (min: -128, max: 127) From "-52" => "-52" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,OPERATING_VOLTAGE_STATUS,0 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","OPERATING_VOLTAGE_STATUS",0] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.OPERATING_VOLTAGE_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,OPERATING_VOLTAGE,2.4 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","OPERATING_VOLTAGE",2.4] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.OPERATING_VOLTAGE ==> UNIT: "undefined" (min: 0, max: 25.2) From "2.4" => "2.4" 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:0,ERROR_CODE,0 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:0","ERROR_CODE",0] 2023-05-01 18:01:22.447 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.0.ERROR_CODE ==> UNIT: "undefined" (min: 0, max: 255) From "0" => "0" 2023-05-01 18:01:22.450 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.CONFIG_PENDING:{"val":false,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505770} 2023-05-01 18:01:22.450 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.DUTY_CYCLE:{"val":false,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505770} 2023-05-01 18:01:22.451 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.LOW_BAT:{"val":true,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505770} 2023-05-01 18:01:22.451 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.UNREACH:{"val":false,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505770} 2023-05-01 18:01:22.451 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.RSSI_DEVICE:{"val":-52,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682956325732} 2023-05-01 18:01:22.451 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.OPERATING_VOLTAGE_STATUS:{"val":0,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505770} 2023-05-01 18:01:22.452 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.OPERATING_VOLTAGE:{"val":2.4,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682956367782} 2023-05-01 18:01:22.452 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.0.ERROR_CODE:{"val":0,"ack":true,"ts":1682956882449,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505771} 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:1,MOTION,false 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:1","MOTION",false] 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.1.MOTION ==> UNIT: "undefined" (min: undefined, max: undefined) From "false" => "false" 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:1,ILLUMINATION,1728 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:1","ILLUMINATION",1728] 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.1.ILLUMINATION ==> UNIT: "undefined" (min: 0, max: 163830) From "1728" => "1728" 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:1,ILLUMINATION_STATUS,0 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:1","ILLUMINATION_STATUS",0] 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.1.ILLUMINATION_STATUS ==> UNIT: "undefined" (min: undefined, max: undefined) From "0" => "0" 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xml multicall : cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652,00095A499AF065:1,MOTION_DETECTION_ACTIVE,true 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) xmlrpc <- event ["cpthlsiob01:hm-rpc.2:84f50a911d7fd708d0d319cfbd91e652","00095A499AF065:1","MOTION_DETECTION_ACTIVE",true] 2023-05-01 18:01:22.459 - [34mdebug[39m: hm-rpc.2 (1063158) hm-rpc.2.00095A499AF065.1.MOTION_DETECTION_ACTIVE ==> UNIT: "undefined" (min: undefined, max: undefined) From "true" => "true" 2023-05-01 18:01:22.505 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.1.MOTION:{"val":false,"ack":true,"ts":1682956882504,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682956882504} 2023-05-01 18:01:22.506 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.1.ILLUMINATION:{"val":1728,"ack":true,"ts":1682956882505,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682956882505} 2023-05-01 18:01:22.506 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.1.ILLUMINATION_STATUS:{"val":0,"ack":true,"ts":1682956882505,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505824} 2023-05-01 18:01:22.506 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.00095A499AF065.1.MOTION_DETECTION_ACTIVE:{"val":true,"ack":true,"ts":1682956882505,"q":0,"from":"system.adapter.hm-rpc.2","user":"system.user.admin","lc":1682869505824} 2023-05-01 18:01:24.371 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12781:{"val":17187.2449,"ack":false,"ts":1682956884369,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884369} 2023-05-01 18:01:24.371 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12781 {"val":17187.2449,"ack":false,"ts":1682956884369,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884369} 2023-05-01 18:01:24.371 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12781: 17187.2449 2023-05-01 18:01:24.371 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12781).State(17187.2449) 2023-05-01 18:01:24.377 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12771:{"val":7.9584000000031665,"ack":false,"ts":1682956884371,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884371} 2023-05-01 18:01:24.378 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12771 {"val":7.9584000000031665,"ack":false,"ts":1682956884371,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884371} 2023-05-01 18:01:24.378 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12771: 7.9584000000031665 2023-05-01 18:01:24.378 - [34mdebug[39m: hm-rega.0 (1062892) 2 pending requests 2023-05-01 18:01:24.379 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12783:{"val":12698.8134,"ack":false,"ts":1682956884376,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884376} 2023-05-01 18:01:24.379 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12783 {"val":12698.8134,"ack":false,"ts":1682956884376,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884376} 2023-05-01 18:01:24.379 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12783: 12698.8134 2023-05-01 18:01:24.379 - [34mdebug[39m: hm-rega.0 (1062892) 3 pending requests 2023-05-01 18:01:24.379 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:24.430 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12771).State(7.9584000000031665) 2023-05-01 18:01:24.438 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:24.469 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12776:{"val":5.458199999999124,"ack":false,"ts":1682956884425,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884425} 2023-05-01 18:01:24.469 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12776 {"val":5.458199999999124,"ack":false,"ts":1682956884425,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956884425} 2023-05-01 18:01:24.469 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12776: 5.458199999999124 2023-05-01 18:01:24.469 - [34mdebug[39m: hm-rega.0 (1062892) 2 pending requests 2023-05-01 18:01:24.489 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12783).State(12698.8134) 2023-05-01 18:01:24.497 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:24.548 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12776).State(5.458199999999124) 2023-05-01 18:01:24.556 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:27.135 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12784:{"val":13996.7461,"ack":false,"ts":1682956887134,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887134} 2023-05-01 18:01:27.135 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12784 {"val":13996.7461,"ack":false,"ts":1682956887134,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887134} 2023-05-01 18:01:27.136 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12784: 13996.7461 2023-05-01 18:01:27.136 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12784).State(13996.7461) 2023-05-01 18:01:27.144 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:27.148 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12778:{"val":9.54739999999947,"ack":false,"ts":1682956887135,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887135} 2023-05-01 18:01:27.149 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12778 {"val":9.54739999999947,"ack":false,"ts":1682956887135,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887135} 2023-05-01 18:01:27.149 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12778: 9.54739999999947 2023-05-01 18:01:27.149 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12778).State(9.54739999999947) 2023-05-01 18:01:27.150 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rega.0./hm-rega.0.12780:{"val":703,"ack":false,"ts":1682956887147,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887147} 2023-05-01 18:01:27.150 - [34mdebug[39m: hm-rega.0 (1062892) stateChange hm-rega.0.12780 {"val":703,"ack":false,"ts":1682956887147,"q":0,"c":"script.js.CPT.CCU-Vars.SmartMeter","from":"system.adapter.javascript.0","user":"system.user.admin","lc":1682956887147} 2023-05-01 18:01:27.151 - [34mdebug[39m: hm-rega.0 (1062892) Set state 12780: 703 2023-05-01 18:01:27.151 - [34mdebug[39m: hm-rega.0 (1062892) 2 pending requests 2023-05-01 18:01:27.158 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:27.208 - [34mdebug[39m: hm-rega.0 (1062892) --> dom.GetObject(12780).State(703) 2023-05-01 18:01:27.217 - [34mdebug[39m: hm-rega.0 (1062892) <-- 2023-05-01 18:01:30.005 - [32minfo[39m: hm-rpc.2 (1063158) xmlrpc <- newDevices 9 2023-05-01 18:01:30.006 - [34mdebug[39m: hm-rpc.2 (1063158) No suitable Lua script, fallback to keys!: function(doc) { if (doc.id.match(/^hm-rpc.[0-9]+.*?[A-Za-z0-9-]+(.[0-9]+)?$/)) { emit(doc._id, {ADDRESS:(doc.native?doc.native.ADDRESS:''),VERSION:(doc.native?doc.native.VERSION:'')}); } } 2023-05-01 18:01:30.118 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.CONFIG_PENDING:null 2023-05-01 18:01:30.120 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.CONFIG_PENDING_ALARM:null 2023-05-01 18:01:30.120 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rpc.2._ALARM/hm-rpc.2.0000D3C9960FBA.0.CONFIG_PENDING_ALARM:null 2023-05-01 18:01:30.122 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.DUTY_CYCLE:null 2023-05-01 18:01:30.124 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.ERROR_CODE:null 2023-05-01 18:01:30.170 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.INSTALL_TEST:null 2023-05-01 18:01:30.171 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.LOW_BAT:null 2023-05-01 18:01:30.173 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.LOW_BAT_ALARM:null 2023-05-01 18:01:30.173 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rpc.2._ALARM/hm-rpc.2.0000D3C9960FBA.0.LOW_BAT_ALARM:null 2023-05-01 18:01:30.217 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.OPERATING_VOLTAGE:null 2023-05-01 18:01:30.220 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.OPERATING_VOLTAGE_STATUS:null 2023-05-01 18:01:30.266 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.RSSI_DEVICE:null 2023-05-01 18:01:30.267 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.RSSI_PEER:null 2023-05-01 18:01:30.313 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.SABOTAGE:null 2023-05-01 18:01:30.316 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.SABOTAGE_ALARM:null 2023-05-01 18:01:30.316 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rpc.2._ALARM/hm-rpc.2.0000D3C9960FBA.0.SABOTAGE_ALARM:null 2023-05-01 18:01:30.362 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.UNREACH:null 2023-05-01 18:01:30.365 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.UNREACH_ALARM:null 2023-05-01 18:01:30.365 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rpc.2._ALARM/hm-rpc.2.0000D3C9960FBA.0.UNREACH_ALARM:null 2023-05-01 18:01:30.410 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.UPDATE_PENDING:null 2023-05-01 18:01:30.413 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.0.UPDATE_PENDING_ALARM:null 2023-05-01 18:01:30.413 - [35msilly[39m: hm-rega.0 (1062892) States user redis pmessage hm-rpc.2._ALARM/hm-rpc.2.0000D3C9960FBA.0.UPDATE_PENDING_ALARM:null 2023-05-01 18:01:30.463 - [35msilly[39m: hm-rega.0 (1062892) Objects system redis pmessage enum./cfg.o.enum.functions.Verschluss:{"desc":"","type":"enum","common":{"name":"Verschluss","members":["hm-rpc.1.OEQ0898529.1","hm-rpc.1.OEQ0897670.1","hm-rpc.2.000F18A98C90E6.1","hm-rpc.2.0007D8A9954FE9.1","hm-rpc.2.001EDF298C70E3.1","hm-rpc.2.00155D89AE9C2E.1","hm-rpc.2.00155D89A39EFB.1","hm-rpc.2.00155D899D3A15.1","hm-rpc.2.00155BE9A43950.1","hm-rpc.2.00155D89AE9DC6.1","hm-rpc.2.0000D569A0AA2D.1","hm-rpc.2.0000D7099D223C.1","hm-rpc.2.0000D7099A620A.1","hm-rpc.2.0000D3C9961013.1","hm-rpc.2.00131A499B8DE3.3"],"smartName":false},"native":{"Name":"Verschluss","TypeName":"ENUM","EnumInfo":""},"from":"system.adapter.hm-rpc.2","ts":1568140730947,"_id":"enum.functions.Verschluss","acl":{"object":1636,"owner":"system.user.admin","ownerGroup":"system.group.administrator"},"user":"system.user.admin"} 2023-05-01 18:01:30.464 - [35msilly[39m: hm-rpc.2 (1063158) Objects system redis pmessage enum./cfg.o.enum.functions.Verschluss:{"desc":"","type":"enum","common":{"name":"Verschluss","members":["hm-rpc.1.OEQ0898529.1","hm-rpc.1.OEQ0897670.1","hm-rpc.2.000F18A98C90E6.1","hm-rpc.2.0007D8A9954FE9.1","hm-rpc.2.001EDF298C70E3.1","hm-rpc.2.00155D89AE9C2E.1","hm-rpc.2.00155D89A39EFB.1","hm-rpc.2.00155D899D3A15.1","hm-rpc.2.00155BE9A43950.1","hm-rpc.2.00155D89AE9DC6.1","hm-rpc.2.0000D569A0AA2D.1","hm-rpc.2.0000D7099D223C.1","hm-rpc.2.0000D7099A620A.1","hm-rpc.2.0000D3C9961013.1","hm-rpc.2.00131A499B8DE3.3"],"smartName":false},"native":{"Name":"Verschluss","TypeName":"ENUM","EnumInfo":""},"from":"system.adapter.hm-rpc.2","ts":1568140730947,"_id":"enum.functions.Verschluss","acl":{"object":1636,"owner":"system.user.admin","ownerGroup":"system.group.administrator"},"user":"system.user.admin"} 2023-05-01 18:01:30.468 - [35msilly[39m: hm-rega.0 (1062892) Objects system redis pmessage enum./cfg.o.enum.rooms.Schlafzimmer:{"_id":"enum.rooms.Schlafzimmer","type":"enum","common":{"name":"Schlafzimmer","desc":"","members":["hm-rpc.2.0019D8A99618A8.1","hm-rpc.2.0019D8A99618A8.2","hm-rpc.2.000C9709AC8B28.1","hm-rpc.2.000895699E5741.2","hm-rpc.2.000895699E5741.5","hm-rpc.2.0001D3C992AC5B.3","hm-rpc.2.0001D3C992AC5B.6","hm-rpc.2.0001D3C9961657.3","hm-rpc.2.0001D3C9961657.6","hm-rpc.2.000915699D3ACD.1","hm-rpc.2.000915699D3ACD.2","hm-rpc.2.0000D3C9961013.1","hm-rpc.2.000A55699D5B43.1","hm-rpc.2.000193C98CA48D.1","hm-rpc.2.000193C98CA48D.2"],"smartName":false},"native":{"Name":"Schlafzimmer","TypeName":"ENUM","EnumInfo":""},"from":"system.adapter.hm-rpc.2","user":"system.user.admin","ts":1568140733528,"acl":{"object":1636,"owner":"system.user.admin","ownerGroup":"system.group.administrator"}} 2023-05-01 18:01:30.468 - [35msilly[39m: hm-rpc.2 (1063158) Objects system redis pmessage enum./cfg.o.enum.rooms.Schlafzimmer:{"_id":"enum.rooms.Schlafzimmer","type":"enum","common":{"name":"Schlafzimmer","desc":"","members":["hm-rpc.2.0019D8A99618A8.1","hm-rpc.2.0019D8A99618A8.2","hm-rpc.2.000C9709AC8B28.1","hm-rpc.2.000895699E5741.2","hm-rpc.2.000895699E5741.5","hm-rpc.2.0001D3C992AC5B.3","hm-rpc.2.0001D3C992AC5B.6","hm-rpc.2.0001D3C9961657.3","hm-rpc.2.0001D3C9961657.6","hm-rpc.2.000915699D3ACD.1","hm-rpc.2.000915699D3ACD.2","hm-rpc.2.0000D3C9961013.1","hm-rpc.2.000A55699D5B43.1","hm-rpc.2.000193C98CA48D.1","hm-rpc.2.000193C98CA48D.2"],"smartName":false},"native":{"Name":"Schlafzimmer","TypeName":"ENUM","EnumInfo":""},"from":"system.adapter.hm-rpc.2","user":"system.user.admin","ts":1568140733528,"acl":{"object":1636,"owner":"system.user.admin","ownerGroup":"system.group.administrator"}} 2023-05-01 18:01:30.471 - [35msilly[39m: hm-rpc.2 (1063158) States user redis pmessage hm-rpc.2./hm-rpc.2.0000D3C9960FBA.1.STATE:null 2023-05-01 18:01:30.472 - [32minfo[39m: hm-rpc.2 (1063158) obsolete device 0000D3C9960FBA deleted 2023-05-01 18:01:30.473 - [32minfo[39m: hm-rpc.2 (1063158) obsolete channel 0000D3C9960FBA.0 "0000D3C9960FBA.0" deleted 2023-05-01 18:01:30.473 - [32minfo[39m: hm-rpc.2 (1063158) obsolete channel 0000D3C9960FBA.1 "0000D3C9960FBA.1" deleted 2023-05-01 18:01:30.474 - [32minfo[39m: hm-rpc.2 (1063158) obsolete channel 0000D3C9960FBA.2 "0000D3C9960FBA.2" deleted

captaindork avatar May 05 '23 11:05 captaindork

Hm strange until now on my updates he does not perform the "delete obsolete channel..." operations. Currently on 3.69.6, will update to .7 then check again.

foxriver76 avatar May 06 '23 19:05 foxriver76

Hi, thx for checking. Just did a HmIP-BWTH update, still same behavior. Was just looking through the config, wondering if there is something „special“… Only things I found:

  • I have https enabled
  • I run iob in Docker, but do not have a Callback Address set. However I guess this is not necessary in my case, as the container has an own IP (not the IP of the docker host) which the CCU can reach directly. I will set it now, but I guess I would have had severe issues if it would be required in my setup…

captaindork avatar May 06 '23 19:05 captaindork

I will re-check tomorrow with current firmware, I could imagine that this makes the difference

foxriver76 avatar May 06 '23 19:05 foxriver76

Unfortunately I was not able to reproduce it also with current firmware. It seems like, that in your case the CCU tells that the device which is currently updating has been deleted, but continues to send status updates for it.

foxriver76 avatar May 07 '23 16:05 foxriver76