Nedis Zigbee Radiator Thermostat (ZBHTR10WT) not working with deconz

[Philap95]

Device

• Product name: Nedis Zigbee Radiator Thermostat
• Manufacturer: _TZE200_hhrtiq0x
• Model identifier: TS0601
• Device type :
  • Thermostat

Already mentioned in https://github.com/dresden-elektronik/deconz-rest-plugin/issues/5495#issuecomment-974677504

Cover

Screenshots

Nodeinfo

Basic

Groups

Scenes

Tuya specific Cluster

OTAU

Time

• nothing

[scobby]

Have two of them here, the thermostat was on sold on mydealz, think currently there will be many people who bought them

[Philap95]

@scobby That is correct. I ordered 6 pieces directly. NBB has sold them for 25€ each.

[Smanar]

But bad news for you, the DDF core don't support yet tuya cluster, and all other code addition are locked, so no way to include this device yet.

[fronsky]

is alternative to use zigbee2mqtt?

[fronsky]

But bad news for you, the DDF core don't support yet tuya cluster, and all other code addition are locked, so no way to include this device yet.

What do you mean with "DDF core"?

[Philap95]

is alternative to use zigbee2mqtt?

For now I switched to Home Assistant with ZHA, zigbee2mqtt should also work, see: https://zigbee.blakadder.com/Nedis_ZBHTR10WT.html

[fronsky]

is alternative to use zigbee2mqtt?

For now I switched to Home Assistant with ZHA, zigbee2mqtt should also work, see: https://zigbee.blakadder.com/Nedis_ZBHTR10WT.html

Thanks for yr advise. I'll give it a try.

[github-actions[bot]]

As there has not been any response in 21 days, this issue has been automatically marked as stale. At OP: Please either close this issue or keep it active It will be closed in 7 days if no further activity occurs.

[TheHaf]

I also ordered two of these a few days ago as there was another sale. I hope they can soon be supported. Anything else that can be done on the user side to help integration?

[Smanar]

The DDF core can now support Tuya cluster, but I have never do that that yet, and not sure it will work but same than https://github.com/dresden-elektronik/deconz-rest-plugin/issues/5844#issuecomment-1084766582

[TheHaf]

If I am not mistaken, this would be done by the deconz GUI, correct? I have my Smart Home stuff running on a raspberry. Can I just unplug the Conbee II stick from there and plug it into my PC or is there a risk of breaking anything if I don't shutdown the deconz service first?

[Smanar]

Can be done with text editor too. Can make a try direclty.

If you unplug a conbee, deconz will just stop, and you have a backup feature in phoscon if you are worried.

Try with this DDF, but same, having logs on headless device is harder, hoping for the result will be visible in the API

{
  "schema": "devcap1.schema.json",
  "manufacturername": "_TZE200_hhrtiq0x",
  "modelid": "TS0601",
  "vendor": "Tuya",
  "product": "TRV",
  "sleeper": false,
  "status": "Gold",
  "subdevices": [
    {
      "type": "$TYPE_THERMOSTAT",
      "restapi": "/sensors",
      "uuid": [
        "$address.ext",
        "0x01",
        "0xef00"
      ],
      "items": [
        {
          "name": "attr/id"
        },
        {
          "name": "attr/lastannounced"
        },
        {
          "name": "attr/lastseen"
        },
        {
          "name": "attr/manufacturername"
        },
        {
          "name": "attr/modelid"
        },
        {
          "name": "attr/name"
        },
        {
          "name": "attr/swversion"
        },
        {
          "name": "attr/type"
        },
        {
          "name": "attr/uniqueid"
        },
        {
          "name": "config/battery"
        },
        {
          "name": "config/heatsetpoint",
          "parse": {"fn": "tuya", "dpid": 2, "eval": "Item.val = Attr.val * 10;"},
          "write": {"fn": "tuya", "dpid": 2, "dt": "0x2b", "eval": "Item.val / 10;"},
          "read": {"fn": "none"}
        },
        {
          "name": "config/locked"
        },
        {
          "name": "config/on"
        },
        {
          "name": "config/reachable"
        },
        {
          "name": "state/lastupdated"
        },
        {
          "name": "state/temperature",
          "parse": {"fn": "tuya", "dpid": 3, "eval": "Item.val = Attr.val * 10;"},
          "read": {"fn": "none"}
        },
        {
          "name": "state/valve"
        },
        {
          "name": "state/windowopen"
        }
      ]
    }
  ]
}

It's totaly experimental, but I m trying to have the temperature and the setpoint

And you need a deconz version >= 2.15.0 beta.

[TheHaf]

edit: I figured out my problem, somehow the problematic light good added to a group that is controlled by a presence sensor. As it's working again now that I removed it from that group, I can try out your DDF. But I'll have to upgrade my deconz to the current beta version first.

orignal: I should have read your message first before trying anything, it looks like I broke something. 😫

~~I went with the route of plugging the stick into the PC. For some reason, it showed only four nodes there in the deconz GUI instead of the registered 50 nodes. So I didn't do anything and plugged it back into the Raspberry. Almost everything seems normal, but one of the lights won't let me change it's brightness and state, it will always turn back on and to a certain level, regardless of whether I change the level or turn it off in Phoscon or via a physical dimmer. In the API view I can see corresponding events that get somehow triggered for that light, changing it back to on and with that certain brightness level. Could it be that plugging the stick into the PC (re)activated an older network setting that now fights with the real network settings? It might be that one of the four nodes was this very same light. I tried restarting deconz but to no avail. I wonder whether I should replug the stick to the PC and delete the nodes there or maybe even click the "leave network" button there as it seems to be a different network. But I am afraid to break even more.~~

I'll need to fix this before I can continue with this thermostat...

[Smanar]

For some reason, it showed only four nodes there in the deconz GUI instead of the registered 50 nodes

Yep this is normal, the network config is on the gateway, but the devices configuration is on the host, if you want to have a complete zigbee network you need to backup on the old machine, and restore it on the new one.

But if you try only with text editor, you can use the headless machine, at least for the moment.

[TheHaf]

Thank you for the explanation! That certainly clears it up for me.

I just tried using the json you provided after updating to the current beta release. I put the json contents into ~/.local/share/dresden-elektronik/deCONZ/devices/nedis-thermostat.json and restarted the deconz service. And lo and behold, the thermostat appears as a sensor:

And here is the API information:

{
    "config": {
        "battery": null,
        "heatsetpoint": null,
        "locked": null,
        "on": true,
        "reachable": true
    },
    "etag": "e2fa0b60601bd684413e6004e8a44318",
    "lastannounced": null,
    "lastseen": "2022-04-01T15:47Z",
    "manufacturername": "_TZE200_hhrtiq0x",
    "modelid": "TS0601",
    "name": "Thermostat 50",
    "state": {
        "lastupdated": "none",
        "temperature": 0,
        "valve": null,
        "windowopen": "Quarantine"
    },
    "type": "ZHAThermostat",
    "uniqueid": "50:32:5f:ff:fe:9f:36:c0-01-ef00"
}

As you can see, the state information is not correct, but I haven't installed the thermostat yet on the radiator, it still sits on my desk. Maybe that is the reason for the wrong state information? Or maybe it has something to do with the fact that I tried to add it to the Zigbee network when I was still on the old version of deconz.

[Smanar]

No, I don't think, we just need to be on the last for test. The first part is done, deconz can see the device, the 0 value can be a convertion error

Can you tried to change the setpoint using manually the device ? To see if you sill have "heatsetpoint": null,

Perhaps we miss that

The read function is special and must only be specified on one item (here state/on). It doesn't actually read a single value but triggers the Tuya device to report all datapoints.

Try to add it in the setheatpoint

        {
          "name": "config/heatsetpoint",
          "parse": {"fn": "tuya", "dpid": 2, "eval": "Item.val = Attr.val * 10;"},
          "write": {"fn": "tuya", "dpid": 2, "dt": "0x2b", "eval": "Item.val / 10;"},
          "read": {"fn": "tuya"},
        },

For the dpid I m almost sure it's the good one, if I m right your device use 0x02 0x03 and 0x02 0x03.

Unfortunately, the only way to reload a DDF on headless deconz, is restarting deconz ....

[TheHaf]

Indeed, when I turn the thermostat, the heatsetpoint updates accordingly: "heatsetpoint": 1900,. I tried locking the thermostat, but the value for locked didn't change unfortunately.

I made the change from none to tuya in the read config of heatsetpoint and now lastupdated and temperature also report:

{
    "config": {
        "battery": null,
        "heatsetpoint": 2200,
        "locked": null,
        "on": true,
        "reachable": true
    },
    "etag": "22a92423034f3a1da3f6bd1a064e3d3c",
    "lastannounced": null,
    "lastseen": "2022-04-01T16:37Z",
    "manufacturername": "_TZE200_hhrtiq0x",
    "modelid": "TS0601",
    "name": "Thermostat 50",
    "state": {
        "lastupdated": "2022-04-01T16:32:51.324",
        "temperature": 1960,
        "valve": null,
        "windowopen": "Quarantine"
    },
    "type": "ZHAThermostat",
    "uniqueid": "50:32:5f:ff:fe:9f:36:c0-01-ef00"
}

So we are slowly making progress. 😸

Don't worry about the debugging process, editing the DDF and restarting deconz on headless is no problem for me, I just use two SSH shells and can iterate quickly. 😺

edit: I just tried setting the heatsetpoint in iobroker. It updates the value according to the API, but the thermostat doesn't show the new value, so the write might also still have a problem.

[Smanar]

Nice ^^, was easier than I thought

To send the request we are using

"write": {"fn": "tuya", "dpid": 2, "dt": "0x2b", "eval": "Item.val / 10;"},

The dpid is good, it s the same than for the read, the convertion too (it work for read with * 10), so the problem is probably dt.

          bool           0x10
          s32 value      0x2b
          enum           0x30
          8-bit bitmap   0x18
          16-bit bitmap  0x19
          32-bit bitmap  0x1b

But for me it's good too ...

[Smanar]

We can try for another one for test, the childlock, on this device it s 0x01 0x07

        {
          "name": "config/locked"
        },

replace with

        {
          "name": "config/locked",
          "parse": {"fn": "tuya", "dpid": 7, "eval": "Item.val = Attr.val;"},
          "write": {"fn": "tuya", "dpid": 7, "dt": "0x10", "eval": "Item.val;"},
          "read": {"fn": "none"}
        },

[TheHaf]

I streamlined the debugging even more using the remote extension in Visual Studio code - I love that tool.

I tested the changes on the childlock, reading works well now. Writing is the same as with the heatsetpoint, I can change the value in iobroker and see the change in the API response, but it won't propagate to the thermostat. So I am not sure about the conversion being the issue here.

[Smanar]

using the remote extension in Visual Studio code

What is it ? I m asking because I realy need some logs to see what happen. On deconz if you enable the flags "DDF" "INFO" and "INFO_L2", you will be able to see the request send by deconz.

I think if you change the childlock mode on the device itself, the value is not updated on the API ?

[TheHaf]

It's an extension that allows Visual Studio Code to directly browse and edit files on a remote machine using SSH, see here for more info.

To enable the debug flags in headless mode, I started deconz in the foreground using the following command: /usr/bin/deCONZ -platform minimal --http-port=80 --dbg-info=2 --dbg-ddf=1 Are these the correct parameters for the flags?

I get lots of logging, but the only thing that stood out when I tried to change a value using iobroker was the following line, which was there 11 times in a row: 18:49:00:590 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x

Regarding your last question, when I change the childlock on the device itself, the value is updated in the API, thanks to the changes to config/locked. That's what I meant in the second paragraph in my last comment, sorry if it was not written clearly.

[Smanar]

Ha good question, I m not sure for "--dbg-ddf" but you have skipped the more used ^^ --dbg-info=1 (need both =1 and =2)

To have some line like

DBG_Printf(DBG_INFO, "writeTuyaData, dpid: 0x%02X, type: 0x%02X, expr: %s\n",

If I m right you need to have (for the childlock)

writeTuyaData, dpid: 0x07, type: 0x010, expr: Item.val Tuya write expression: Item.val--> 1

I m not sure for true false o or 1 ....

Edit:

Ok have perhaps found the issue for childlock try as expression Item.val == 1 ? 1 : 0;

[TheHaf]

I checked the wiki for the debug flags, unfortunately it doesn't mention anything about the ddf debug flag yet. And I can't find anything in the code in the repository regarding the flag parsing. Are you sure about writing --dbg-info=1 --dbg-info=2? When I do it this way, it only seems to print the messages from level 1. According to the wiki, level 2 should contain the level 1 messages as well, which seems to be the case, when I compare the output from using only level 1 with using only level 2. Anyway, I can't find anything with writeTuyData regardless of which debug flags I use. When I use only the dbg-ddf flag, I get the following lines when switching the childlock on the device itself.

09:58:11:908 50:32:5f:ff:fe:9f:36:c0-01-ef00/config/locked expression: Item.val = Attr.val; --> true
09:58:18:728 50:32:5f:ff:fe:9f:36:c0-01-ef00/config/locked expression: Item.val = Attr.val; --> false

However there is nothing when switching the value via iobroker. When I use dbg-info=2 I still get the lines about No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x.

All of this was done after trying to use Item.val == 1 ? 1 : 0; in the eval of the config/locked entry.

[Smanar]

Good question, in fact on the code there is both, and can select only 1 of them using the GUI

DBG_Printf(DBG_INFO_L2, "No Tuya productId entry found for manufacturername: %s\n", qPrintable(manufacturerName->toString())); DBG_Printf(DBG_INFO, "writeTuyaData, dpid: 0x%02X, type: 0x%02X, expr: %s\n",

So I m not sure what happen if using both or only one using the command line .... (It's not on api code), but the line I need are just used with "info".

In fact I m trying to trace this fonction https://github.com/dresden-elektronik/deconz-rest-plugin/blob/master/device_access_fn.cpp#L797

As you can see all debug line are with "info" But this code is triggered when you try to change the childlock using the API (when you use the "write" part on the DDF. Try with "error" too, it s strange you realy have nothing when you try it with iobroker

[TheHaf]

Indeed, the relevant lines in that function are all level 1. So it seems we don't even reach line 851 and are returning early on one of the pre-conditions. Maybe there is something wrong with my changes? Here is what I currently have for the childlock:

        {
          "name": "config/locked",
          "parse": {"fn": "tuya", "dpid": 7, "eval": "Item.val = Attr.val;"},
          "write": {"fn": "tuya", "dpid": 7, "dt": "0x10", "eval": "Item.val == 1 ? 1 : 0;"},
          "read": {"fn": "none"}
        },

I re-tried it just now with --dbg-info=1 --dbg-ddf=1 --dbg-error=2, there is unfortunately still nothing in the log when I change the value in iobroker. I also tried it with db-error set to 1, just in case, but no change in the outcome.

[Smanar]

Ha yep sorry, I m asking on discord ATM. It seem the write command can't work perfectly for the moment, I m not sure but we probably need the PR called "Add DDF for Danfoss Ally thermostat"

[TheHaf]

Ok, well at least reading out the values seems to work except for the battery. Maybe the PR #3927 you mentioned will help with the writing, so I keep my fingers crossed for that. 😸

edit: Oh, I just took a look at it and it seems to be stuck in PR limbo. I hope it'll get merged before long if we really depend on it.

[kvanisterdael]

Same here: reading of values is ok. I can set the heatsetpoint via the PUT command and the change is reflected in the config I read via the REST API. However on the display of the Thermostat the value is not updated.

[Smanar]

Hello, the Swoop PR is merged, but now there is a problem to add our values need to edit the code. I can make change in blind mode but to go faster there is someone able to compile the code ?

I will explain how to do but need someone with a Tuya TRV (any) and a full/real Linux OS.

[macinsight]

Hello, the Swoop PR is merged, but now there is a problem to add our values need to edit the code. I can make change in blind mode but to go faster there is someone able to compile the code ?

I will explain how to do but need someone with a Tuya TRV (any) and a full/real Linux OS.

@Smanar: I’ve got the exact TRV this issue is about and am running Arch (btw). Also I’m eager to get this thin integrated, as I’ve got two of them. What do you need me to do?

[Smanar]

Perfect, I will make a code change to test tommorow or this week end if I don't have time. Will be a test to enable config/heatsetpoint and config/childlock. I m asking some confirmations to swoop and manup.

So I will give you in same time the procedure to compile the lib, it will just replace 1 file (and can make a backup), so not realy dangerous, will be based on the last code, and ofc will use the previous DDF.

[kvanisterdael]

While you're at it, maybe a test to disable the 'open window' detection as well, as this is enabled by default.

[TheHaf]

I can also give it a try with the code change when it's comitted.

[Smanar]

BTW I m seing on the future version, the 2.15.1, the childlock could be tested without recompilation, the code is ready for tuya too.

So waiting for this version will be released, to try the test version, the procedure is explained here https://github.com/dresden-elektronik/deconz-rest-plugin/wiki/Compiling-the-REST-plugin-for-device-specific-testing So it make

sudo apt install deconz-dev
git clone --branch tuya_trv_test https://github.com/Smanar/deconz-rest-plugin.git
cd deconz-rest-plugin
qmake && make -j2
sudo cp ../libde_rest_plugin.so /usr/share/deCONZ/plugins

You probably need to switch on the beta repo if needed. If you have a small raspberry, it can freeze during compilation, my pi 3 do, so remove "-j2"

It don't impact your zigbee database, but can use a lot the CPU (at least the first time, compilation will be faster after). To rollback fastly you can make a backup of the file /usr/share/deCONZ/plugins/libde_rest_plugin.so in another folder. The procedure change only this file. And if you don't close deconz, the file replacement will crash it, so in all case you will need to restart it.

You need to use first the config/heatsetpoint to enable the tuya reporting (because of the "read": {"fn": "tuya"} in the DDF. Then you can try to set a temperature (this command use value) and the childlock (this command use a bool)

If I m right you will see in log when doing the request (with "info" and "info_l2")

writeTuyaData, dpid: 0x07, type: 0x010, expr: Item.val
Tuya write expression: Item.val--> 1

The DDF for the _TZE200_hhrtiq0x

{
  "schema": "devcap1.schema.json",
  "manufacturername": "_TZE200_hhrtiq0x",
  "modelid": "TS0601",
  "vendor": "Tuya",
  "product": "TRV",
  "sleeper": false,
  "status": "Gold",
  "subdevices": [
    {
      "type": "$TYPE_THERMOSTAT",
      "restapi": "/sensors",
      "uuid": [
        "$address.ext",
        "0x01",
        "0xef00"
      ],
      "items": [
        {
          "name": "attr/id"
        },
        {
          "name": "attr/lastannounced"
        },
        {
          "name": "attr/lastseen"
        },
        {
          "name": "attr/manufacturername"
        },
        {
          "name": "attr/modelid"
        },
        {
          "name": "attr/name"
        },
        {
          "name": "attr/swversion"
        },
        {
          "name": "attr/type"
        },
        {
          "name": "attr/uniqueid"
        },
        {
          "name": "config/battery"
        },
        {
          "name": "config/heatsetpoint",
          "parse": {"fn": "tuya", "dpid": 2, "eval": "Item.val = Attr.val * 10;"},
          "write": {"fn": "tuya", "dpid": 2, "dt": "0x2b", "eval": "Item.val / 10;"},
          "read": {"fn": "tuya"}
        },
        {
          "name": "config/locked",
          "parse": {"fn": "tuya", "dpid": 7, "eval": "Item.val = Attr.val;"},
          "write": {"fn": "tuya", "dpid": 7, "dt": "0x10", "eval": "Item.val;"},
          "read": {"fn": "none"}
        },
        {
          "name": "config/on"
        },
        {
          "name": "config/reachable"
        },
        {
          "name": "state/lastupdated"
        },
        {
          "name": "state/temperature",
          "parse": {"fn": "tuya", "dpid": 3, "eval": "Item.val = Attr.val * 10;"},
          "read": {"fn": "none"}
        },
        {
          "name": "state/valve"
        },
        {
          "name": "state/windowopen"
        }
      ]
    }
  ]
}

Have not enabled yet the "open window", it's a test, but if the childlock is working will be easy to add it.

[macinsight]

Tried setting the temperature using curl -X PUT http://192.168.178.28/api/E55CDE04B9/sensors/15/config -H "Content-Type: application/json" -d '{ "heatsetpoint": 1500, this had no discernible effect (Althought the response was success.) The API reports the heatsetpoint correctly afterwards. The display on the TRV does not change. There also was no discernible change in temperature from 20 to 15 degrees over the testing period.

Also tried setting the childlock using curl -X PUT http://192.168.178.28/api/E55CDE04B9/sensors/15/config -H "Content-Type: application/json" -d '{ "locked": true }', this also had no discernible effect. The display did not change either.

Also, I am unable to find writeTuyaData, dpid: 0x07, type: 0x010, expr: Item.val Tuya write expression: Item.val--> 1 (Or anything concerning tuya, really), with the following launch arguments: /usr/bin/deCONZ --platform minimal --dbg-info=2 --dbg-error=2.

The logs produced during testing are here: https://macinsight.net/tuya_trv_test.txt (Had no better idea. Pastebin doesn't have the ability to use the shell for uploads, and termbin crapped out on me during the upload. So my own box it is.)

[Smanar]

Ha, there is a problem ^^, I don't know how to enable "info" and "info_l2" in command line. And you miss all "info" Nevermind, have updated the code to display more debug line with "info_l2" , less talkative

cd deconz-rest-plugin
git pull
qmake && make -j2
sudo cp ../libde_rest_plugin.so /usr/share/deCONZ/plugins

Will be faster this time, if you can send me the same logs when you make same procedure pls ?

[macinsight]

Sure, gonna get to testing right now.

[macinsight]

No noticeable change from previous testing, logs will follow.

[Smanar]

Yep, I haven't updated code, just add logging and display them with "info_l2" (easier to read)

[TheHaf]

I also compiled it now and tried it out using the debug flag parameters --dbg-info=2 --dbg-ddf=1 --dbg-error=2. We should really try to figure out how these debug flags actually work altogether and then add it to the documentation. Could this be something from the Qt framework or some external logging library?

As for the result of my test, I also don't get any different result than before, the change is not propagated to the device. One thing that I note is the line with debug test 3, I guess that is one of your added debug messages, that seems to right where I tried to change the lock setting. Here is the full log, the change was roughly around timestamp 17:56:16:175, where the debug message can be seen:

(...)
17:56:13:851 Idle timer triggered
17:56:13:851 Force binding of attribute reporting for node Flurlicht
17:56:13:851 Force read attributes for ZHAOpenClose SensorNode Türsensor Büro
17:56:13:853 rule event /config/localtime: 17:56:12.850 -> 17:56:13.851 (1001ms)
17:56:14:426 poll node 00:17:88:01:04:40:82:ec-0b
17:56:14:426 Poll light node Wohndecke 1
17:56:14:479 read attributes of 0x00178801044082EC cluster: 0x0006: [ 17:56:14:479 0x0000 17:56:14:479 ]
17:56:14:480 add task 161 type 19 to 0x00178801044082EC cluster 0x0006 req.id 18
17:56:14:480 Poll APS request 18 to 0x00178801044082EC cluster: 0x0006
17:56:14:562 Poll APS confirm 18 status: 0x00
17:56:14:562 Erase task req-id: 18, type: 19 zcl seqno: 25 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:14:582 Node data 0x00178801044082ec profileId: 0x0104, clusterId: 0x0006
17:56:14:582 0x00178801044082EC: update ZCL value 0x0B/0x0006/0x0000 after 0 s
17:56:14:850 schedule 3 diff 16721, Sat Apr 9 22:34:55 2022
17:56:14:852 rule event /config/localtime: 17:56:13.851 -> 17:56:14.850 (999ms)
17:56:15:425 poll node 84:18:26:00:00:0e:24:23-03
17:56:15:425 Poll light node Esstisch 3
17:56:15:477 Poll APS request to 0x84182600000E2423 cluster: 0x0006 dropped, values are fresh enough
17:56:15:850 schedule 3 diff 16720, Sat Apr 9 22:34:55 2022
17:56:15:850 Wait 2s till query finished
17:56:15:852 rule event /config/localtime: 17:56:14.850 -> 17:56:15.850 (1000ms)
17:56:16:175 debug test 3
17:56:16:176 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:178 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:179 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:180 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:181 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:183 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:184 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:185 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:186 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:187 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:188 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
17:56:16:197 Websocket 192.168.178.57:8857 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
17:56:16:198 Websocket 127.0.0.1:40032 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
17:56:16:350 Daylight now: solarNoon, status: 170, daylight: 1, dark: 0
17:56:16:525 poll node 00:17:88:01:03:a1:f4:ed-0b
17:56:16:525 Poll light node Flurlicht
17:56:16:578 read attributes of 0x0017880103A1F4ED cluster: 0x0006: [ 17:56:16:578 0x0000 17:56:16:578 ]
17:56:16:578 add task 171 type 19 to 0x0017880103A1F4ED cluster 0x0006 req.id 31
17:56:16:578 Poll APS request 31 to 0x0017880103A1F4ED cluster: 0x0006
17:56:16:663 Poll APS confirm 31 status: 0x00
17:56:16:663 Erase task req-id: 31, type: 19 zcl seqno: 26 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:16:673 Node data 0x0017880103a1f4ed profileId: 0x0104, clusterId: 0x0006
17:56:16:673 0x0017880103A1F4ED: update ZCL value 0x0B/0x0006/0x0000 after 0 s
17:56:16:851 schedule 3 diff 16719, Sat Apr 9 22:34:55 2022
17:56:16:852 rule event /config/localtime: 17:56:15.850 -> 17:56:16.851 (1001ms)
17:56:17:000 APS-DATA.indication from child 0x4536
17:56:17:675 poll node 58:8e:81:ff:fe:d4:ae:49-01
17:56:17:675 Poll light node Blitzwolf-2
17:56:17:727 read attributes of 0x588E81FFFED4AE49 cluster: 0x0006: [ 17:56:17:727 0x0000 17:56:17:727 ]
17:56:17:727 add task 177 type 19 to 0x588E81FFFED4AE49 cluster 0x0006 req.id 40
17:56:17:727 Poll APS request 40 to 0x588E81FFFED4AE49 cluster: 0x0006
17:56:17:777 Poll APS confirm 40 status: 0x00
17:56:17:777 Erase task req-id: 40, type: 19 zcl seqno: 28 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:17:830 Node data 0x588e81fffed4ae49 profileId: 0x0104, clusterId: 0x0006
17:56:17:830 0x588E81FFFED4AE49: update ZCL value 0x01/0x0006/0x0000 after 0 s
17:56:17:851 schedule 3 diff 16718, Sat Apr 9 22:34:55 2022
17:56:17:852 rule event /config/localtime: 17:56:16.851 -> 17:56:17.851 (1000ms)
17:56:18:538 poll node 84:18:26:00:00:0e:32:bf-03
17:56:18:538 Poll light node Esstisch 2
17:56:18:590 Poll APS request to 0x84182600000E32BF cluster: 0x0006 dropped, values are fresh enough
17:56:18:619 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x1282
17:56:18:850 schedule 3 diff 16717, Sat Apr 9 22:34:55 2022
17:56:18:852 rule event /config/localtime: 17:56:17.851 -> 17:56:18.850 (999ms)
17:56:19:686 poll node 90:fd:9f:ff:fe:08:b8:47-01
17:56:19:686 Poll light node Arbeitsfläche
17:56:19:738 read attributes of 0x90FD9FFFFE08B847 cluster: 0x0006: [ 17:56:19:738 0x0000 17:56:19:738 ]
17:56:19:738 add task 186 type 19 to 0x90FD9FFFFE08B847 cluster 0x0006 req.id 52
17:56:19:738 Poll APS request 52 to 0x90FD9FFFFE08B847 cluster: 0x0006
17:56:19:762 Poll APS confirm 52 status: 0x00
17:56:19:762 Erase task req-id: 52, type: 19 zcl seqno: 29 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:19:801 Node data 0x90fd9ffffe08b847 profileId: 0x0104, clusterId: 0x0006
17:56:19:801 0x90FD9FFFFE08B847: update ZCL value 0x01/0x0006/0x0000 after 0 s
17:56:19:850 schedule 3 diff 16716, Sat Apr 9 22:34:55 2022
17:56:19:852 rule event /config/localtime: 17:56:18.850 -> 17:56:19.850 (1000ms)
17:56:20:347 APS-DATA.indication from child 0xE29A
17:56:20:347 Node data 0x00158d00070b36f7 profileId: 0x0104, clusterId: 0x0000
17:56:20:348 Update Sensor 0x00158D00070B36F7 Basic Cluster
17:56:20:349 [INFO] - No button map for: lumi.sensor_magnet.aq2, unicast to: 0x0000, endpoint: 0x01, cluster: BASIC (0x0000), command: 0x0A, payload: 01FF421D01219F0B0328190421A81305212F00062401000000000A210000641000, zclSeq: 16
17:56:20:349 ZCL attribute report 0x00158D00070B36F7 for cluster: 0x0000, ep: 0x01, frame control: 0x1C, mfcode: 0x115F
17:56:20:349    payload: 01ff421d01219f0b0328190421a81305212f00062401000000000a210000641000
17:56:20:349 0x00158D00070B36F7 extract Xiaomi special attribute 0xFF01
17:56:20:349    01 battery 2975 (0x0B9F)
17:56:20:349    03 Device temperature 25 °C
17:56:20:349    04 unknown 5032 (0x13A8)
17:56:20:349    05 RSSI dB (?) 47 (0x002F)
17:56:20:349    06 LQI (?) 4294967296 (0x0100000000)
17:56:20:349    0a Parent NWK 0 (0x0000)
17:56:20:349    64 on/off 0
17:56:20:354 Websocket 192.168.178.57:8857 send message: {"config":{"battery":91,"on":true,"reachable":true,"temperature":2500},"e":"changed","id":"44","r":"sensors","t":"event","uniqueid":"00:15:8d:00:07:0b:36:f7-01-0006"} (ret = 15)
17:56:20:354 Websocket 127.0.0.1:40032 send message: {"config":{"battery":91,"on":true,"reachable":true,"temperature":2500},"e":"changed","id":"44","r":"sensors","t":"event","uniqueid":"00:15:8d:00:07:0b:36:f7-01-0006"} (ret = 15)
17:56:20:355 Websocket 192.168.178.57:8857 send message: {"e":"changed","id":"44","r":"sensors","state":{"lastupdated":"2022-04-09T15:56:20.350","open":false},"t":"event","uniqueid":"00:15:8d:00:07:0b:36:f7-01-0006"} (ret = 15)
17:56:20:355 Websocket 127.0.0.1:40032 send message: {"e":"changed","id":"44","r":"sensors","state":{"lastupdated":"2022-04-09T15:56:20.350","open":false},"t":"event","uniqueid":"00:15:8d:00:07:0b:36:f7-01-0006"} (ret = 15)
17:56:20:675 poll node 00:17:88:01:04:40:82:ec-0b
17:56:20:675 Poll light node Wohndecke 1
17:56:20:727 read attributes of 0x00178801044082EC cluster: 0x0006: [ 17:56:20:727 0x0000 17:56:20:727 ]
17:56:20:727 add task 191 type 19 to 0x00178801044082EC cluster 0x0006 req.id 59
17:56:20:727 Poll APS request 59 to 0x00178801044082EC cluster: 0x0006
17:56:20:763 Poll APS confirm 59 status: 0x00
17:56:20:763 Erase task req-id: 59, type: 19 zcl seqno: 30 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:20:783 Node data 0x00178801044082ec profileId: 0x0104, clusterId: 0x0006
17:56:20:783 0x00178801044082EC: update ZCL value 0x0B/0x0006/0x0000 after 0 s
17:56:20:850 schedule 3 diff 16715, Sat Apr 9 22:34:55 2022
17:56:20:852 rule event /config/localtime: 17:56:19.850 -> 17:56:20.850 (1000ms)
17:56:21:253 New websocket 192.168.178.57:8863 (state: 3)
17:56:21:676 poll node 84:18:26:00:00:0e:24:23-03
17:56:21:676 Poll light node Esstisch 3
17:56:21:728 Poll APS request to 0x84182600000E2423 cluster: 0x0006 dropped, values are fresh enough
17:56:21:850 schedule 3 diff 16714, Sat Apr 9 22:34:55 2022
17:56:21:852 rule event /config/localtime: 17:56:20.850 -> 17:56:21.850 (1000ms)
17:56:22:039 SC tick --> StateRead
17:56:22:039 SC state change failed: 50:32:5f:ff:fe:9f:36:c0-01-ef00
17:56:22:849 binding/unbinding timeout srcAddr: 0x84182600000E32BF, retry
17:56:22:850 schedule 3 diff 16713, Sat Apr 9 22:34:55 2022
17:56:22:850 poll node 00:17:88:01:03:a1:f4:ed-0b
17:56:22:850 Poll light node Flurlicht
17:56:22:851 rule event /config/localtime: 17:56:21.850 -> 17:56:22.850 (1000ms)
17:56:22:900 read attributes of 0x0017880103A1F4ED cluster: 0x0006: [ 17:56:22:900 0x0000 17:56:22:900 ]
17:56:22:900 add task 201 type 19 to 0x0017880103A1F4ED cluster 0x0006 req.id 72
17:56:22:900 Poll APS request 72 to 0x0017880103A1F4ED cluster: 0x0006
17:56:22:961 Poll APS confirm 72 status: 0x00
17:56:22:961 Erase task req-id: 72, type: 19 zcl seqno: 31 send time 0, profileId: 0x0104, clusterId: 0x0006
17:56:22:973 Node data 0x0017880103a1f4ed profileId: 0x0104, clusterId: 0x0006
17:56:22:973 0x0017880103A1F4ED: update ZCL value 0x0B/0x0006/0x0000 after 0 s
17:56:23:850 schedule 3 diff 16712, Sat Apr 9 22:34:55 2022
17:56:23:852 rule event /config/localtime: 17:56:22.850 -> 17:56:23.850 (1000ms)
17:56:23:925 poll node 58:8e:81:ff:fe:d4:ae:49-01
17:56:23:925 Poll light node Blitzwolf-2
(...)

edit: added more following lines of the log to include the SC lines.

[Smanar]

I guess that is one of your added debug messages

Yep exactly.

We should really try to figure out how these debug flags actually work altogether and then add it to the documentation

I m asking ATM.

I m seing 2 mac adress, the device actually used is the 50:32:5f:ff:fe:9f:36:c0-01-ef00 ? So yes It seem there is something

17:56:22:039 SC tick --> StateRead
17:56:22:039 SC state change failed: 50:32:5f:ff:fe:9f:36:c0-01-ef00

It's like the code is waiting for a return from the device, but there is no logs indicating something was send to the device ...

Have added some more debug line, if you can make a last try ? BTW have you the GUI, if yes, a screen log capture can be enought.

[TheHaf]

Regarding the debug flags, after comparing the messages when using --dbg-info=2 to the code, I am now convinced that the command line flag for level 2 contains the level 1 messages as well. For instance you changed the message SC tick --> StateRead in your latest commit to be in level 2 instead of level 1 but I did see it before as well when using the flag for level 2.

I have not seen how the messages come together in the UI yet, only the logging window with the check boxes. If the check boxes really toggle the levels disjunct, then the behavior of the command line flags is definitely different to the UI.

Yes, the device is the one with the id 50:32:5f:ff:fe:9f:36:c0-01-ef00.

I tried out your latest changes just now and have additional log messages, such as 09:12:22:906 Device managed by DDF during the time when the change occurred. Regarding the debug test messages, I can only see the ones numbered 3 and 7.

log output:

09:12:22:851 Poll light node Esstisch 3
09:12:22:851 Idle timer triggered
09:12:22:851 Force binding of attribute reporting for node Flurlicht
09:12:22:851 Force read attributes for ZHASwitch SensorNode TRADFRI Dimmer Küche
09:12:22:852 rule event /config/localtime: 09:12:21.850 -> 09:12:22.851 (1001ms)
09:12:22:857 read attributes of 0x84182600000E2423 cluster: 0x0006: [ 09:12:22:858 0x0000 09:12:22:858 ]
09:12:22:858 add task 177 type 19 to 0x84182600000E2423 cluster 0x0006 req.id 53
09:12:22:858 Poll APS request 53 to 0x84182600000E2423 cluster: 0x0006
09:12:22:906 debug test 3
09:12:22:906 Device managed by DDF
09:12:22:906 ressource ok
09:12:22:907 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:908 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:910 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:911 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:912 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:913 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:915 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:916 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:917 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:918 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:919 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
09:12:22:928 Websocket 127.0.0.1:37518 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
09:12:22:929 Websocket 192.168.178.57:11837 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
09:12:22:929 Websocket 127.0.0.1:37610 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
09:12:22:929 Websocket 192.168.178.57:11842 send message: {"config":{"battery":null,"heatsetpoint":600,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
09:12:22:929 debug test 7
09:12:22:942 Poll APS confirm 53 status: 0x00
09:12:22:942 Erase task req-id: 53, type: 19 zcl seqno: 155 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:22:969 Node data 0x84182600000e2423 profileId: 0x0104, clusterId: 0x0006
09:12:22:969 0x84182600000E2423: update ZCL value 0x03/0x0006/0x0000 after 0 s
09:12:23:850 schedule 2 diff 25449, Sun Apr 10 16:16:32 2022
09:12:23:850 schedule 3 diff 48152, Sun Apr 10 22:34:55 2022
09:12:23:852 rule event /config/localtime: 09:12:22.851 -> 09:12:23.850 (999ms)
09:12:23:925 poll node 00:17:88:01:03:a1:f4:ed-0b
09:12:23:925 Poll light node Flurlicht
09:12:23:977 read attributes of 0x0017880103A1F4ED cluster: 0x0006: [ 09:12:23:977 0x0000 09:12:23:977 ]
09:12:23:977 add task 183 type 19 to 0x0017880103A1F4ED cluster 0x0006 req.id 60
09:12:23:977 Poll APS request 60 to 0x0017880103A1F4ED cluster: 0x0006
09:12:24:061 Poll APS confirm 60 status: 0x00
09:12:24:061 Erase task req-id: 60, type: 19 zcl seqno: 156 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:24:084 Node data 0x0017880103a1f4ed profileId: 0x0104, clusterId: 0x0006
09:12:24:085 0x0017880103A1F4ED: update ZCL value 0x0B/0x0006/0x0000 after 0 s
09:12:24:675 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x1282
09:12:24:850 schedule 2 diff 25448, Sun Apr 10 16:16:32 2022
09:12:24:850 schedule 3 diff 48151, Sun Apr 10 22:34:55 2022
09:12:24:851 rule event /config/localtime: 09:12:23.850 -> 09:12:24.850 (1000ms)
09:12:25:025 poll node 58:8e:81:ff:fe:d4:ae:49-01
09:12:25:025 Poll light node Blitzwolf-2
09:12:25:077 read attributes of 0x588E81FFFED4AE49 cluster: 0x0006: [ 09:12:25:077 0x0000 09:12:25:077 ]
09:12:25:077 add task 188 type 19 to 0x588E81FFFED4AE49 cluster 0x0006 req.id 68
09:12:25:077 Poll APS request 68 to 0x588E81FFFED4AE49 cluster: 0x0006
09:12:25:161 Poll APS confirm 68 status: 0x00
09:12:25:161 Erase task req-id: 68, type: 19 zcl seqno: 157 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:25:168 Node data 0x588e81fffed4ae49 profileId: 0x0104, clusterId: 0x0006
09:12:25:168 0x588E81FFFED4AE49: update ZCL value 0x01/0x0006/0x0000 after 0 s
09:12:25:850 binding/unbinding timeout srcAddr: 0x90FD9FFFFE29E7F9, retry
09:12:25:850 schedule 2 diff 25447, Sun Apr 10 16:16:32 2022
09:12:25:850 schedule 3 diff 48150, Sun Apr 10 22:34:55 2022
09:12:25:852 rule event /config/localtime: 09:12:24.850 -> 09:12:25.850 (1000ms)
09:12:25:925 poll node 00:17:88:01:04:38:0a:81-0b
09:12:25:925 Poll light node Wohndecke 2
09:12:25:978 read attributes of 0x0017880104380A81 cluster: 0x0006: [ 09:12:25:978 0x0000 09:12:25:978 ]
09:12:25:978 add task 193 type 19 to 0x0017880104380A81 cluster 0x0006 req.id 74
09:12:25:978 Poll APS request 74 to 0x0017880104380A81 cluster: 0x0006
09:12:26:061 Poll APS confirm 74 status: 0x00
09:12:26:061 Erase task req-id: 74, type: 19 zcl seqno: 158 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:26:080 Node data 0x0017880104380a81 profileId: 0x0104, clusterId: 0x0006
09:12:26:080 0x0017880104380A81: update ZCL value 0x0B/0x0006/0x0000 after 0 s
09:12:26:253 read attributes of 0x0017880104380A81 cluster: 0x0008: [ 09:12:26:253 0x0000 09:12:26:253 ]
09:12:26:253 add task 195 type 19 to 0x0017880104380A81 cluster 0x0008 req.id 77
09:12:26:253 Poll APS request 77 to 0x0017880104380A81 cluster: 0x0008
09:12:26:363 Poll APS confirm 77 status: 0x00
09:12:26:363 Erase task req-id: 77, type: 19 zcl seqno: 159 send time 0, profileId: 0x0104, clusterId: 0x0008
09:12:26:383 Node data 0x0017880104380a81 profileId: 0x0104, clusterId: 0x0008
09:12:26:383 0x0017880104380A81: update ZCL value 0x0B/0x0008/0x0000 after 0 s
09:12:26:850 schedule 2 diff 25446, Sun Apr 10 16:16:32 2022
09:12:26:850 schedule 3 diff 48149, Sun Apr 10 22:34:55 2022
09:12:26:852 rule event /config/localtime: 09:12:25.850 -> 09:12:26.850 (1000ms)
09:12:26:901 Bind response success for 0x90fd9ffffe29e7f9 ep: 0x01 cluster: 0x0000
09:12:26:937 poll node 7c:b0:3e:aa:00:ab:3c:f1-03
09:12:26:937 Poll light node Kinderzimmerdecke
09:12:26:990 read attributes of 0x7CB03EAA00AB3CF1 cluster: 0x0006: [ 09:12:26:990 0x0000 09:12:26:990 ]
09:12:26:990 add task 199 type 19 to 0x7CB03EAA00AB3CF1 cluster 0x0006 req.id 84
09:12:26:990 Poll APS request 84 to 0x7CB03EAA00AB3CF1 cluster: 0x0006
09:12:27:085 Poll APS confirm 84 status: 0x00
09:12:27:085 Erase task req-id: 84, type: 19 zcl seqno: 160 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:27:095 Node data 0x7cb03eaa00ab3cf1 profileId: 0x0104, clusterId: 0x0006
09:12:27:095 0x7CB03EAA00AB3CF1: update ZCL value 0x03/0x0006/0x0000 after 0 s
09:12:27:850 schedule 2 diff 25445, Sun Apr 10 16:16:32 2022
09:12:27:850 schedule 3 diff 48148, Sun Apr 10 22:34:55 2022
09:12:27:851 rule event /config/localtime: 09:12:26.850 -> 09:12:27.850 (1000ms)
09:12:28:040 poll node 90:fd:9f:ff:fe:29:e7:f9-01
09:12:28:040 Poll light node Spüle
09:12:28:092 read attributes of 0x90FD9FFFFE29E7F9 cluster: 0x0006: [ 09:12:28:092 0x0000 09:12:28:092 ]
09:12:28:092 add task 204 type 19 to 0x90FD9FFFFE29E7F9 cluster 0x0006 req.id 90
09:12:28:092 Poll APS request 90 to 0x90FD9FFFFE29E7F9 cluster: 0x0006
09:12:28:161 Poll APS confirm 90 status: 0x00
09:12:28:161 Erase task req-id: 90, type: 19 zcl seqno: 161 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:28:203 Node data 0x90fd9ffffe29e7f9 profileId: 0x0104, clusterId: 0x0006
09:12:28:204 0x90FD9FFFFE29E7F9: update ZCL value 0x01/0x0006/0x0000 after 0 s
09:12:28:851 schedule 2 diff 25444, Sun Apr 10 16:16:32 2022
09:12:28:851 schedule 3 diff 48147, Sun Apr 10 22:34:55 2022
09:12:28:852 rule event /config/localtime: 09:12:27.850 -> 09:12:28.851 (1001ms)
09:12:29:025 poll node 58:8e:81:ff:fe:d3:8d:ce-01
09:12:29:025 Poll light node Blitzwolf-1
09:12:29:077 read attributes of 0x588E81FFFED38DCE cluster: 0x0006: [ 09:12:29:077 0x0000 09:12:29:077 ]
09:12:29:077 add task 209 type 19 to 0x588E81FFFED38DCE cluster 0x0006 req.id 98
09:12:29:077 Poll APS request 98 to 0x588E81FFFED38DCE cluster: 0x0006
09:12:29:160 Poll APS confirm 98 status: 0x00
09:12:29:160 Erase task req-id: 98, type: 19 zcl seqno: 162 send time 0, profileId: 0x0104, clusterId: 0x0006
09:12:29:167 Node data 0x588e81fffed38dce profileId: 0x0104, clusterId: 0x0006
09:12:29:167 0x588E81FFFED38DCE: update ZCL value 0x01/0x0006/0x0000 after 0 s
09:12:29:850 schedule 2 diff 25443, Sun Apr 10 16:16:32 2022
09:12:29:850 schedule 3 diff 48146, Sun Apr 10 22:34:55 2022
09:12:29:852 rule event /config/localtime: 09:12:28.851 -> 09:12:29.850 (999ms)
09:12:29:925 poll node 84:18:26:00:00:0e:29:78-03
09:12:29:925 Poll light node Esstisch 4
09:12:29:977 read attributes of 0x84182600000E2978 cluster: 0x0006: [ 09:12:29:977 0x0000 09:12:29:977 ]
09:12:29:977 add task 214 type 19 to 0x84182600000E2978 cluster 0x0006 req.id 104
09:12:29:977 Poll APS request 104 to 0x84182600000E2978 cluster: 0x0006
09:12:30:061 Poll APS confirm 104 status: 0x00

[Smanar]

I am now convinced that the command line flag for level 2 contains the level 1 messages as well

Swoop say that too, but I have check some debug line from your logs and all are with DBG_INFO_L2 and realy miss lot of them.

But You still have a succed message when you make the request ?

09:12:22:906 debug test 3
09:12:22:906 Device managed by DDF
09:12:22:906 ressource ok

This is good new, we are in the fonction that manage parametre, and all values are fine, but

                else if (rid.suffix == RConfigHeatSetpoint) // Signed integer
                {
                    DBG_Printf(DBG_INFO_L2, "debug test 4\n");

The code don't use the config/heatsetpoint at all .... (no "debug test 4") There is something wrong in the request or there is something in the code that break this part, but in this situation you can"t have a succed message ... But there is websocket notification just after, so something have changed.

Edit:

And we have exactly 11 "No Tuya productId entry found for manufacturername" the exact number than in the RConfigHeatSetpoint part. It's like some debug lines are skipped ....

[TheHaf]

Yes, I get a success message. I also tried it using curl instead of iobroker this time and curl responds for example when setting the lock with [{"success":{"/sensors/50/config/locked":true}}].

I just tried setting a debug message before that long if/else if/... block to check the actual contents of rid.suffix. For setting the lock I get config/locked and for setting a heatsetpoint I get config/heatsetpoint as the value of rid.suffix. So this seems to be right.

That made me realize though that I didn't clarify what exactly I performed in my last comment, sorry about any misunderstanding. I have now a log for setting the heatsetpoint as well, and there you can see the debug messages 4 and 5 as well:

16:00:59:381 Erase task req-id: 106, type: 19 zcl seqno: 75 send time 0, profileId: 0x0104, clusterId: 0x0006
16:00:59:402 Node data 0x84182600000e2978 profileId: 0x0104, clusterId: 0x0006
16:00:59:402 0x84182600000E2978: update ZCL value 0x03/0x0006/0x0000 after 0 s
16:00:59:850 schedule 2 diff 933, Sun Apr 10 16:16:32 2022
16:00:59:851 schedule 3 diff 23636, Sun Apr 10 22:34:55 2022
16:00:59:851 Wait 2s till query finished
16:00:59:852 rule event /config/localtime: 16:00:58.850 -> 16:00:59.851 (1001ms)
16:01:00:044 debug test 3
16:01:00:044 Device managed by DDF
16:01:00:044 ressource ok
16:01:00:044 i1-rid.suffix=config/heatsetpoint
16:01:00:044 i2-rid.suffix=config/heatsetpoint
16:01:00:044 debug test 4
16:01:00:046 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:048 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:050 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:051 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:053 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:055 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:057 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:058 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:060 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:062 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:064 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
16:01:00:064 debug test 5
16:01:00:075 Websocket 192.168.178.57:13100 send message: {"config":{"battery":null,"heatsetpoint":1500,"locked":false,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
16:01:00:076 Websocket 192.168.178.57:13108 send message: {"config":{"battery":null,"heatsetpoint":1500,"locked":false,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
16:01:00:076 Websocket 127.0.0.1:42208 send message: {"config":{"battery":null,"heatsetpoint":1500,"locked":false,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
16:01:00:076 debug test 7
16:01:00:350 Daylight now: solarNoon, status: 170, daylight: 1, dark: 0
16:01:00:350 poll node 84:18:26:00:00:0e:31:3e-03
16:01:00:350 Poll light node Esstisch 1

So it does get into the else if part.

The two lines before the debug test 4 show that I can receive both messages with DBG_INFO and DBG_INFO_L2 using my command line parameters.

The 11 lines with "No Tuya productId entry found for manufacturername" happen with changing the lock state as well, not just with changing the heatsetpoint. That seems to happen in R_GetProductId in product_match.cpp. It looks to me as if there is not yet a product entry for _TZE200_hhrtiq0x.

edit: I added the following line to the products map in product_match.cpp and the message about the missing productId entry is gone at least.

{"_TZE200_hhrtiq0x", "TS0601", "Nedis", "Nedis ZBHTR10WT TRV"},

But I guess there's more about the productId that needs to be taken care of, right?

[Smanar]

"No Tuya productId entry found for manufacturername"

This part will be removed soon ^^, it s the old legacy code. Now we are using the DDF, and the DDF core can work only for new device (we are checking first knowed device and the last test is the DDF presence), so for device that are generaly not in this list.

So now it's better, debug line are all here. I think I have found the problem, have removed some debug line and add some more. But this time you have too a code modification for the config/heatsetpoint. I m trying to write the value before waiting for a return.

[TheHaf]

Ok, then I'll just ignore that part from now on, good to know.

I discarded my changes and pulled the current state of the branch again. And lo and behold, when I change the heatsetpoint now, the display on the device lights up and shows the new value. 👍 Here is the log:

ttributes for ZHASwitch SensorNode SYMFONISK Sound Controller
18:21:40:852 Node data 0x84182600000e313e profileId: 0x0104, clusterId: 0x0300
18:21:40:852 0x84182600000E313E: added ZCL value 0x03/0x0300/0x0007
18:21:40:852 0x84182600000E313E: added ZCL value 0x03/0x0300/0x0008
18:21:40:852 0x84182600000E313E: added ZCL value 0x03/0x0300/0x4001
18:21:40:853 rule event /config/localtime: 18:21:39.850 -> 18:21:40.851 (1001ms)
18:21:40:907 read attributes of 0x7CB03EAA00B1DE7B cluster: 0x0006: [ 18:21:40:907 0x0000 18:21:40:907 ]
18:21:40:907 add task 162 type 19 to 0x7CB03EAA00B1DE7B cluster 0x0006 req.id 25
18:21:40:907 Poll APS request 25 to 0x7CB03EAA00B1DE7B cluster: 0x0006
18:21:40:961 Poll APS confirm 25 status: 0x00
18:21:40:961 Erase task req-id: 25, type: 19 zcl seqno: 36 send time 0, profileId: 0x0104, clusterId: 0x0006
18:21:41:009 Node data 0x7cb03eaa00b1de7b profileId: 0x0104, clusterId: 0x0006
18:21:41:009 0x7CB03EAA00B1DE7B: added ZCL value 0x03/0x0006/0x0000
18:21:41:011 Websocket 192.168.178.57:9896 send message: {"attr":{"id":"2","lastannounced":"2021-10-26T09:33:39Z","lastseen":"2022-04-10T16:21Z","manufacturername":"OSRAM","modelid":"Plug 01","name":"Stehlampe","swversion":"V1.04.12","type":"On/Off plug-in unit","uniqueid":"7c:b0:3e:aa:00:b1:de:7b-03"},"e":"changed","id":"2","r":"lights","t":"event","uniqueid":"7c:b0:3e:aa:00:b1:de:7b-03"} (ret = 335)
18:21:41:012 Websocket 192.168.178.57:9910 send message: {"attr":{"id":"2","lastannounced":"2021-10-26T09:33:39Z","lastseen":"2022-04-10T16:21Z","manufacturername":"OSRAM","modelid":"Plug 01","name":"Stehlampe","swversion":"V1.04.12","type":"On/Off plug-in unit","uniqueid":"7c:b0:3e:aa:00:b1:de:7b-03"},"e":"changed","id":"2","r":"lights","t":"event","uniqueid":"7c:b0:3e:aa:00:b1:de:7b-03"} (ret = 335)
18:21:41:012 Websocket 192.168.178.57:9896 send message: {"e":"changed","id":"7","r":"groups","state":{"all_on":false,"any_on":false},"t":"event"} (ret = 21034256)
18:21:41:012 Websocket 192.168.178.57:9910 send message: {"e":"changed","id":"7","r":"groups","state":{"all_on":false,"any_on":false},"t":"event"} (ret = 21034256)
18:21:41:036 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:038 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:039 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:040 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:041 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:043 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:044 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:045 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:046 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:047 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:048 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:21:41:048 debug test 5
18:21:41:064 Websocket 192.168.178.57:9896 send message: {"config":{"battery":null,"heatsetpoint":1200,"locked":false,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
18:21:41:064 Websocket 192.168.178.57:9910 send message: {"config":{"battery":null,"heatsetpoint":1200,"locked":false,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
18:21:41:064 debug test 7
18:21:41:064 SC tick --> StateCallFunction
18:21:41:064 debug test 2
18:21:41:064 debug test 1
18:21:41:064 writeTuyaData, dpid: 0x02, type: 0x2B, expr: Item.val / 10;
18:21:41:065 Tuya write expression: Item.val / 10; --> 120
18:21:41:781 poll node 84:18:26:00:00:0e:32:bf-03
18:21:41:781 Poll light node Esstisch 2
18:21:41:834 Poll APS request to 0x84182600000E32BF cluster: 0x0006 dropped, values are fresh enough
18:21:41:850 schedule 3 diff 15194, Sun Apr 10 22:34:55 2022
18:21:41:852 rule event /config/localtime: 18:21:40.851 -> 18:21:41.850 (999ms)
18:21:42:852 schedule 3 diff 15193, Sun Apr 10 22:34:55 2022
18:21:42:854 rule event /config/localtime: 18:21:41.850 -> 18:21:42.852 (1002ms)
18:21:42:925 poll node 90:fd:9f:ff:fe:08:b8:47-01
18:21:42:925 Poll light node Arbeitsfläche
18:21:42:977 read attributes of 0x90FD9FFFFE08B847 cluster: 0x0006: [ 18:21:42:977 0x0000 18:21:42:977 ]
18:21:42:977 add task 172 type 19 to 0x90FD9FFFFE08B847 cluster 0x0006 req.id 40
18:21:42:977 Poll APS request 40 to 0x90FD9FFFFE08B847 cluster: 0x0006
18:21:43:063 Poll APS confirm 40 status: 0x00
18:21:43:063 Erase task req-id: 40, type: 19 zcl seqno: 39 send time 0, profileId: 0x0104, clusterId: 0x0006
18:21:43:103 Node data 0x90fd9ffffe08b847 profileId: 0x0104, clusterId: 0x0006
18:21:43:103 0x90FD9FFFFE08B847: update ZCL value 0x01/0x0006/0x0000 after 0 s
18:21:43:850 schedule 3 diff 15192, Sun Apr 10 22:34:55 2022
18:21:43:852 rule event /config/localtime: 18:21:42.852 -> 18:21:43.850 (998ms)

Changing the locked status still won't update the device unfortunately, here is the log for that:

: update ZCL value 0x0B/0x0006/0x0000 after 0 s
18:23:10:474 Bind response success for 0x84182600000e2423 ep: 0x03 cluster: 0x0300
18:23:10:474 update ddf Classic B40 TW - LIGHTIFY index 62
18:23:10:474 skip configure report for cluster: 0x0300 attr: 0x0003 of node 0x84182600000E2423 (wait reading or unsupported)
18:23:10:474 skip configure report for cluster: 0x0300 attr: 0x0004 of node 0x84182600000E2423 (wait reading or unsupported)
18:23:10:474 configure reporting rq seq 145 for 0x84182600000E2423, attribute 0x0300/0x0007
18:23:10:474 configure reporting rq seq 145 for 0x84182600000E2423, attribute 0x0300/0x0008
18:23:10:549 ZCL configure reporting rsp seq: 139 0xF0D1B8000013D6E9 for ep: 0x01 cluster: 0x0008 attr: 0x0000 status: 0x00
18:23:10:638 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 8, node: 0x2B07
18:23:10:737 ZCL configure reporting rsp seq: 145 0x84182600000E2423 for ep: 0x03 cluster: 0x0300 attr: 0x0007 status: 0x00
18:23:10:737 ZCL configure reporting rsp seq: 145 0x84182600000E2423 for ep: 0x03 cluster: 0x0300 attr: 0x0008 status: 0x00
18:23:10:793 poll node 7c:b0:3e:aa:00:ab:3c:f1-03
18:23:10:793 Poll light node Kinderzimmerdecke
18:23:10:845 Poll APS request to 0x7CB03EAA00AB3CF1 cluster: 0x0006 dropped, values are fresh enough
18:23:10:850 schedule 3 diff 15105, Sun Apr 10 22:34:55 2022
18:23:10:852 rule event /config/localtime: 18:23:09.851 -> 18:23:10.850 (999ms)
18:23:10:880 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 9, node: 0x6F4E
18:23:11:348 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:349 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:350 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:351 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:353 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:354 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:355 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:356 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:357 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:358 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:360 No Tuya productId entry found for manufacturername: _TZE200_hhrtiq0x
18:23:11:585 Websocket 192.168.178.57:9896 send message: {"config":{"battery":null,"heatsetpoint":1200,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
18:23:11:585 Websocket 192.168.178.57:9910 send message: {"config":{"battery":null,"heatsetpoint":1200,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
18:23:11:585 Websocket 127.0.0.1:40534 send message: {"config":{"battery":null,"heatsetpoint":1200,"locked":true,"on":true,"reachable":true},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 18)
18:23:11:586 debug test 7
18:23:11:850 schedule 3 diff 15104, Sun Apr 10 22:34:55 2022
18:23:11:852 rule event /config/localtime: 18:23:10.850 -> 18:23:11.850 (1000ms)
18:23:11:936 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 9, node: 0x8C3E
18:23:11:936 0x90FD9FFFFE29E7F9: added ZCL value 0x01/0x0000/0x4000
18:23:11:936 update ddf TRADFRI transformer 10W index 70
18:23:11:936 configure reporting rq seq 147 for 0x90FD9FFFFE29E7F9, attribute 0x0000/0x4000
18:23:11:937 update ddf TRADFRI transformer 10W index 70
18:23:11:937 configure reporting rq seq 148 for 0x90FD9FFFFE29E7F9, attribute 0x0006/0x0000
18:23:12:059 ZCL configure reporting rsp seq: 147 0x90FD9FFFFE29E7F9 for ep: 0x01 cluster: 0x0000 attr: 0x4000 status: 0x00
18:23:12:103 ZCL configure reporting rsp seq: 148 0x90FD9FFFFE29E7F9 for ep: 0x01 cluster: 0x0006 attr: 0x0000 status: 0x00
18:23:12:206 poll node 90:fd:9f:ff:fe:29:e7:f9-01
18:23:12:206 Poll light node Spüle
18:23:12:254 Poll APS request to 0x90FD9FFFFE29E7F9 cluster: 0x0006 dropped, values are fresh enough
18:23:12:851 schedule 3 diff 15103, Sun Apr 10 22:34:55 2022
18:23:12:854 rule event /config/localtime: 18:23:11.850 -> 18:23:12.851 (1001ms)
18:23:12:929 void deCONZ::zmNode::setFetched(deCONZ::RequestId, bool) fetched item: 9, node: 0x8C3E
18:23:12:929 update ddf TRADFRI transformer 10W index 70
18:23:12:930 skip configure report for cluster: 0x0008 attr: 0x0000 of node 0x90FD9FFFFE29E7F9 (wait reading or unsupported)
18:23:13:275 poll node 58:8e:81:ff:fe:d3:8d:ce-01
18:23:13:275 Poll light node Blitzwolf-1
18:23:13:327 Poll APS request to 0x588E81FFFED38DCE cluster: 0x0006 dropped, values are fresh enough
18:23:13:843 Websocket 192.168.178.57:9896 send message: {"attr":{"id":"50","lastannounced":null,"lastseen":"2022-04-10T16:23Z","manufacturername":"_TZE200_hhrtiq0x","modelid":"TS0601","name":"Thermostat 50","swversion":null,"type":"ZHAThermostat","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 2128620552)
18:23:13:844 Websocket 192.168.178.57:9910 send message: {"attr":{"id":"50","lastannounced":null,"lastseen":"2022-04-10T16:23Z","manufacturername":"_TZE200_hhrtiq0x","modelid":"TS0601","name":"Thermostat 50","swversion":null,"type":"ZHAThermostat","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 2128620552)
18:23:13:844 Websocket 127.0.0.1:40534 send message: {"attr":{"id":"50","lastannounced":null,"lastseen":"2022-04-10T16:23Z","manufacturername":"_TZE200_hhrtiq0x","modelid":"TS0601","name":"Thermostat 50","swversion":null,"type":"ZHAThermostat","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"},"e":"changed","id":"50","r":"sensors","t":"event","uniqueid":"50:32:5f:ff:fe:9f:36:c0-01-ef00"} (ret = 2128620552)
18:23:13:844 debug test 7
18:23:13:851 schedule 3 diff 15102, Sun Apr 10 22:34:55 2022
18:23:13:853 rule event /config/localtime: 18:23:12.851 -> 18:23:13.851 (1000ms)
18:23:13:854 APS-DATA.indication from child 0x4536

I tried it with the write eval for config/locked being Item.val; as well as Item.val == 1 ? 1 : 0;, to no avail. The log is from the first try.

[Smanar]

Haa ^^, good new, and realy usefull logs. I have edited the code only for the setheatpint request (was a test) Will add all the other for tomorow.

[TheHaf]

Oh, guess I should have taken a look at the latest commit. 😉 I tried changing the code for the locked state in the same way in lines 1577+:

StateChange change2(StateChange::StateCallFunction, SC_WriteZclAttribute, task.req.dstEndpoint());
change2.addTargetValue(rid.suffix, data.uinteger);
rsub->addStateChange(change2);

And it works! Most of the time. Actually, sometimes it won't update. I also noticed odd behavior with changing the heatsetpoint, sometimes it won't update, and sometimes it updates but it will return a weird value. For instance, I set it to 10°C and it does that but afterwards the API states the value 16.3°C. Or I set it to 16°c and it does that but the API will change to 9°C afterwards.

[Smanar]

Something worring is you don't have thoses logs for childlock (and have added some debug line in a suspicious fonction)

17:56:22:039 SC tick --> StateRead 17:56:22:039 SC state change failed: 50:32:5f:ff:fe:9f:36:c0-01-ef00

Have added your code + the window open detection DPID for windows detection is 18 = 0x12

        {
          "name": "config/windowopen_set",
          "parse": {"fn": "tuya", "dpid": 18, "eval": "Item.val = Attr.val;"},
          "write": {"fn": "tuya", "dpid": 18, "dt": "0x10", "eval": "Item.val;"},
          "read": {"fn": "none"}
        },

18:21:41:064 writeTuyaData, dpid: 0x02, type: 0x2B, expr: Item.val / 10;
18:21:41:065 Tuya write expression: Item.val / 10; --> 120

And something strange, from my memory tuya answer immedialtly after a change, and I don't see return on your logs.

You don't have logs when you have values problem ?

And have confirmation, when you use --dbg-info=2, you need to have "info" AND "info_l2".