Issue: Deconz Docker becomes unresponsive with Tuya TS011F Plugs DDF

iisworks · February 7, 2022, 6:19am

Thanks for the update! Could this somehow explain my deconz slowless issues? Because I think all my plugs should/could use the same DDF? By now things look a bit better performance wise though, since I removed the SHP15 plugs though. My remaining issue now is that I have no working DDF which correctly includes the sensors in the api, I tried for hours to change settings in the DDF by trial & error but nothing worked reliably so far.

How does this work for similar devices with different Manufacturer Names (I guess Tuya is notorious for that) that could use the same DDF config, for example Tuya TS011F Reporting or Polling Plugs? Problem with them is that a combination of manufacturername + FW determines if they are Reporting or Polling. For example SHP15 (_TZ3000_mraovvmm) with latest FW has no reporting any more, older ones did, with _TZ3000_w0qqde0g the other way around. I know for example zigbee2mqtt has several configs for TS011F + FW level (polling/reporting): https://github.com/Koenkk/zigbee2mqtt
Is it possible to use 1 DDF for multiple manufacturername + FW levels, or an attempt to fallback on modelid when no manufacturername was found?
Does “path” actually matter?
“manufacturername”: “_TZ3000_xxxxxxxx”,
“modelid”: “TS011F”,
“path”: “/devices/TS011F.json”,
Is there a working sample for Tuya reporting plugssomewhere?

[Update] These is still an issue with my plugs in combination with DDF, some kind of memory leak (normally around 200MB):

Not sure if it’s somehow related to the same issue, but I’ll restore a backup without the new plugs that require DDF…
Note: Apparently the BW-SHP15’s also already use NEO DDF after the restore (without any issues):
DEV found DDF for 0x84FD27FFFECE7BEA, path: /usr/share/deCONZ/devices/neo/NAS-WR01B.json

iisworks · February 8, 2022, 10:00am

I just upgraded to 2.14.1 and re-added the new plugs again (Hybrid mode). That kind of works. I can see them updating just fine when I look at the measurement cluster - Power in vnc, but somehow the updates don’t alsays seem to be reflected in the api. Switching On/off does work fine, also in the api. I had to configure Reporting timing manually on each cluster though?

Any idea:

Does the fact that changes are visible on the cluster mean that the DDF itself is valid?
Why is the reporting (as defined in the DDF, e.g. 3-300-1) not set on plugs?
Why are changes I see on the cluster from vnc not reflected in the api?

Can someone explain what could cause this?

Mimiix · February 8, 2022, 10:27am

Great to see some progress here guys:)!

Smanar · February 8, 2022, 6:56pm

Why is the reporting (as defined in the DDF, e.g. 3-300-1) not set on plugs?

You have checked them using the GUI ? select a cluster, select an attribute, double click then “read config”

Why are changes I see on the cluster from vnc not reflected in the api?

Not sure the DDF is working for me. Perhaps it s the GUI that is not refreshed ?

iisworks · February 8, 2022, 7:10pm

Thanks, this should be configured from the DDF and not have to be set manually, right? It seems the “Reporting config” eventually got set on all plugs as configured in the DDF after I toggled Hybride mode, disconnected the plugs from power and restarted deconz and waited for things to settle a while (so not entirely sure what helped).

Now the plugs do report well to the api 95% of the time, but I still feel there is a bug + memory leak somewhere. Because as soon as I added 4 of these new Tuya plugs, deconz feels less snappy than before. Usually there is no delay at all, but now sometimes when I try to click somewhere or drag a window it seems as if the system freezes up for a few seconds. If I look at the debug window, I also see no logs being added for a bit. And exactly at that same time, the api also seems to be delayed for a few seconds (no updates in my 3rd party app).
It looks a lot better than 2.14.0 though, and it seems to at least keep running now. Memory usage on the container still seems higher than usual (now 350MB instead of normally <200MB), so I will keep an eye on it overnight.

iisworks · February 9, 2022, 6:52am

Memory usage of the docker container seemed to be still low this morning (140MB) and the plugs do respond, although sluggish.

I managed to capture L2 logging while toggling On/Off on a plug a few times. It responds with a delay, deconz seemed to freeze for 1-2s (log windows also stopped).

Hopefully that gives someting to the devs to look into?

[Update] Unfortunately when the zigbee network getws used more during the day, the extreme slowness & memory leak occurred again. Eventually deconz became unresponsive and I had to restart the container.

iisworks · February 9, 2022, 3:26pm

Small update. I ordered a separate Conbee II stick and pugged it in to my Windows 11 PC.
I then added a new _TZ3000_w0qqde0g + _TZ3000_gjnozsaz plug and this is the L2 log (no 3rd party app installed).

I don’t see the plug “Active Power” updating in the clusters with the built-in NEO DDF (pressing “Read” works)? Could someone check if this all looks normal?

[Update] When I enable “Silver”, they start reporting.
L2 logging in that case:

Smanar · February 9, 2022, 3:55pm

I don’t understand it works with “silver” ? What was your setting when it haven’t worked ?

iisworks · February 9, 2022, 4:45pm

I mean the DDF setting, it was on “Gold” before and then the cluster did not seem to update automatically. After I set it to Silver, the NEO ddf was picked u0p/applied and it started working.

Note that on the “real” live network I am having issues in Silver mode (L2 Logs in post before the previous one). Can you please check both logs to see if they look normal?

I also noticed I have a DB of 33MB now!

I just can’t get 2.14.1 stable with the new TS011F plugs.

Smanar · February 10, 2022, 5:45pm

This is normal, on the DDF (if you are uysing the same) you can see

  "status": "Silver",
  "path": "/devices/ts011f.json",

So if you set only “gold” the DDF is not used.

And I don’t see what the DDF core can write on the DB to increase the size …
You have some SQL knowledge to check the file ? I don’t know the normal size, but 33 Mb seem a lot for me, how many device you have on this network ?
Check if deconz don’t create “ghost” device.

iisworks · February 10, 2022, 6:21pm

Yeah, I just meant to indicate that there is something very wrong in my setup with about 60 devices and after I added the new plugs.

Can someone who knows what to look for please take a look at the L2 logs I pasted in the last few posts (especialy the one in the home setup Post 13)? I would really like to know if something looks wrong?

Swoop · February 10, 2022, 9:41pm

You apparently got interference issues based on the 2nd log. There’s 4 0xA7 errors and more than 20 0xE9 errors in there.

Regarding your previous questions, it should absolutely be doable to create one DDF fitting multiple devices either deviating in manufacturer name or in firware version (or both). However, this is also limited to a certain extend on identical clusters, attirbutes and resource items being used accross the devices.

Check out the DDF cheat sheet https://github.com/dresden-elektronik/deconz-rest-plugin/wiki/DDF-cheat-sheet#readwriteparse-functions

If you scroll down a little bit, there’s some insights on what you can use within JS. What you probably need would go into this direction:

if (R.item('attr/manufacturername').val === "ABC" && R.item('attr/swversion').val === "123")
{
    Item.val = Attr.val;
}
else if (R.item('attr/manufacturername').val === "XYZ" && R.item('attr/swversion').val === "789")
{
    Item.val = Attr.val / 10;
}

manup · February 11, 2022, 12:57am

I think we need more options to match a DDF to a specific firmware version, or more generic to specific item values. I’ve talked with Smanar a while ago about this there is already an idea for it.

To be frank I’m strongly against having this logic in the item handlers, as this would bring the mess we had in C++ land to DDFs Comparing strings like manufacturer name, modelid, swversion should be done once and only once to select the right DDF for a device.

iisworks · February 11, 2022, 6:24am

@Swoop Sorry for the confusion, but the 2nd set of logs is from another Conbee II stick with the same plugs, but the Conbee was plugged directly in a Win11 laptop. So maybe that’s why the interference comes from. These logs were just meant to provide some clean L2 logging of the plug DDF pairing process.

Can you please also take a look at the logs from the “production” network where the real issues are
(running 2.14.1 in Docker on my NAS, about 60 devices, no interference there, just DDF issues related to the Tuya plugs):

Swoop · February 11, 2022, 8:12am

@iisworks I took a look at both logs you referred to in Post 13 and shared what I spotted and looks odd (apart from the fact that in the first log, your plug(s) apparently do not have the respective sensors).

As Smanar already pointed out, a DB size of 33MB is way to high. I also got around 60 devices and the size is less than 0,5MB. This probably goes hand in hand with memory consumption to a certain extend.

@manup I also would only do so if I’m forced to and that was meant as an individual workaround based on the given circumstances rather than general advice But yes, it seems to get more and more common that calculations need to be amended based on the firmware version (see also the latest innr plug).

iisworks · February 11, 2022, 8:43am

Sorry, I pasted the right link but mentioned the wrong post #, I meant the one log in Post 12:

My DB is usually around 1.3MB and everything works perfectly fine. When I start adding the new Plugs using DDF (and messing with DDF Silver/Hybrid mode, Hot reload etc.), things start to fall apart in a matter of hours (slowness, DB increase). The log mentioned here may contain some clues?

I opened a backup of a 76MB database of a few days ago. I have no idea what to look for, but 50.000 entries in the “sensors” table does not look right (looks like each device gets duplicated 100s of times):

Smanar · February 11, 2022, 4:42pm

Nice catch ^^.
I think we have found a new issue.
Can you confirm the deconz version you are using, pls ? (sorry to ask again)

I m seing an old bug with FF as endpoint on the first one, but for the other, it s something new for me.

iisworks · February 11, 2022, 4:52pm

[Updated] The logs were all from 2.14.1, the database was I think from from 2.14.1 (but maybe 2.14.0).

BTW: Can the huge amount of sensors explain the slowness/memory issues I was experiencing?

Smanar · February 12, 2022, 9:35am

For me yes, it 's a cause or a result but there is a link for me.
But I don’t see the problem, why only you (I never see this issue before) and even the bug with the sensor with FF as endpoint is corrected now.

And there is some “securities” in the code to prevent that. You don’t see something special on thoses lines ? an invisible char for exemple.

iisworks · February 12, 2022, 4:01pm

@Smanar, @manup I am pretty sure it has to do with DDF (TS011F) in 2.14.1. When I am adding/updating these plugs, strange things happen. I just saw this when I re-added a plug that previously existed. I see the same thing happening: deconz becomes very unresponsive , DB size increases and updates are delayed a lot (this happens within minutes!). It must be a bug somewhere.

BTW: Notice the many “REPLACE INTO …” sql statements, which keep repeating. Do they maybe create new sensor entries instead of updating them (not only for the plugs)? Please let me know if someone needs such a DB sample PM-ed.
SQLite Replace Statement - Tutlane.

Full L2 log:


15:57:36:116 	payload: 0b05292f00
15:57:36:117 Websocket 172.17.0.1:59794 send message: {"e":"changed","id":"288","r":"sensors","state":{"current":281,"lastupdated":"2022-02-12T15:57:36.115","power":47,"voltage":227},"t":"event","uniqueid":"a4:c1:38:91:cb:9d:7c:e8-01-0b04"} (ret = 186)
15:57:36:146 APS-DATA.indication srcAddr: 0xecd4, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0B04, lqi: 255, rssi: -76
15:57:36:518 ZCL attribute report 0xA4C13891CB9D7CE8 for cluster: 0x0B04, ep: 0x01, frame control: 0x18, mfcode: 0x0000 
15:57:36:519 	payload: 0805212b01
15:57:36:520 Websocket 172.17.0.1:59794 send message: {"e":"changed","id":"288","r":"sensors","state":{"current":299,"lastupdated":"2022-02-12T15:57:36.148","power":47,"voltage":227},"t":"event","uniqueid":"a4:c1:38:91:cb:9d:7c:e8-01-0b04"} (ret = 186)
15:57:36:764 APS-DATA.request id: 117, addrmode: 0x03, addr: 0x00158d000520aba2, profile: 0x0000, cluster: 0x0031, ep: 0x00 -> 0x00 queue: 0 len: 2 tx.options 0x00
15:57:36:777 APS-DATA.confirm id: 117, status: 0x00 SUCCESS
15:57:36:777 APS-DATA.confirm request id: 117 -> confirmed, timeout 2072044165
15:57:37:186 poll node 5c:02:72:ff:fe:74:16:51-01
15:57:37:187 Poll light node Keuken Spot 1
15:57:37:239 Poll APS request to 0x5C0272FFFE741651 cluster: 0x0006 dropped, values are fresh enough
15:57:38:190 poll node 58:8e:81:ff:fe:d3:8e:bc-01
15:57:38:242 read attributes of 0x588E81FFFED38EBC cluster: 0x0006: [ 
15:57:38:242 0x0000 
15:57:38:242 ]
15:57:38:243 add task 1449 type 19 to 0x588E81FFFED38EBC cluster 0x0006 req.id 124
15:57:38:243 Poll APS request 124 to 0x588E81FFFED38EBC cluster: 0x0006
15:57:38:299 APS-DATA.request id: 124, addrmode: 0x03, addr: 0x588e81fffed38ebc, profile: 0x0104, cluster: 0x0006, ep: 0x01 -> 0x01 queue: 1 len: 5 tx.options 0x00
15:57:38:315 Poll APS confirm 124 status: 0x00
15:57:38:316 Erase task req-id: 124, type: 19 zcl seqno: 150 send time 0, profileId: 0x0104, clusterId: 0x0006
15:57:38:316 APS-DATA.confirm id: 124, status: 0x00 SUCCESS
15:57:38:317 APS-DATA.confirm request id: 124 -> erase from queue
15:57:38:324 APS-DATA.indication srcAddr: 0xdb67, srcEp: 0x01 dstAddrMode: 2, profile: 0x0104, cluster: 0x0400, lqi: 255, rssi: -71
15:57:38:325 APS-DATA.request id: 124 erase from queue
15:57:38:325 Node data 0x04cf8cdf3c7d1330 profileId: 0x0104, clusterId: 0x0400
15:57:38:325 0x04CF8CDF3C7D1330: update ZCL value 0x01/0x0400/0x0000 after 0 s
15:57:38:326 [INFO] - No button map for: lumi.sen_ill.mgl01, unicast to: 0x0000, endpoint: 0x01, cluster: 0x0400, command: 0x0A, payload: 0000211354, zclSeq: 76
15:57:38:327 ZCL attribute report 0x04CF8CDF3C7D1330 for cluster: 0x0400, ep: 0x01, frame control: 0x18, mfcode: 0x0000 
15:57:38:327 	payload: 0000211354
15:57:38:335 Websocket 172.17.0.1:59794 send message: {"e":"changed","id":"260","r":"sensors","state":{"dark":false,"daylight":true,"lastupdated":"2022-02-12T15:57:38.326","lightlevel":21523,"lux":142},"t":"event","uniqueid":"04:cf:8c:df:3c:7d:13:30-01-0400"} (ret = 205)
15:57:38:599 DB save zll database items 0x00000081
15:57:38:600 DB sql exec REPLACE INTO nodes (id, state, mac, name, groups, endpoint, modelid, manufacturername, swbuildid, ritems) VALUES ('25', 'normal', '84:fd:27:ff:fe:ce:99:dc-01', 'PC Alena', '65520', '1', 'TS011F', '_TZ3000_mraovvmm', '67', '{"attr/id":"25","attr/lastannounced":null,"attr/lastseen":"2022-02-12T15:57Z","attr/manufacturername":"_TZ3000_mraovvmm","attr/modelid":"TS011F","attr/name":"PC Alena","attr/swversion":"67","attr/type":"On/Off plug-in unit","attr/uniqueid":"84:fd:27:ff:fe:ce:99:dc-01","state/alert":"none","state/on":false,"state/reachable":true}')
15:57:38:601 DB sql exec REPLACE INTO nodes (id, state, mac, name, groups, endpoint, modelid, manufacturername, swbuildid, ritems) VALUES ('18', 'normal', '84:fd:27:ff:fe:ce:7b:ea-01', 'PC Kevin', '65520', '1', 'TS011F', '_TZ3000_mraovvmm', '67', '{"attr/id":"18","attr/lastannounced":null,"attr/lastseen":"2022-02-12T15:57Z","attr/manufacturername":"_TZ3000_mraovvmm","attr/modelid":"TS011F","attr/name":"PC Kevin","attr/swversion":"67","attr/type":"On/Off plug-in unit","attr/uniqueid":"84:fd:27:ff:fe:ce:7b:ea-01","state/alert":"none","state/on":true,"state/reachable":true}')
15:57:38:602 DB sql exec REPLACE INTO nodes (id, state, mac, name, groups, endpoint, modelid, manufacturername, swbuildid, ritems) VALUES ('39', 'normal', 'a4:c1:38:91:cb:9d:7c:e8-01', 'PC JH 1', '65520', '1', 'TS011F', '_TZ3000_gjnozsaz', '', '{"attr/id":"39","attr/lastannounced":null,"attr/lastseen":"2022-02-12T15:57Z","attr/manufacturername":"_TZ3000_gjnozsaz","attr/modelid":"TS011F","attr/name":"PC JH 1","attr/swversion":null,"attr/type":"On/Off plug-in unit","attr/uniqueid":"a4:c1:38:91:cb:9d:7c:e8-01","state/alert":"none","state/on":true,"state/reachable":true}')
15:57:38:603 DB sql exec REPLACE INTO nodes (id, state, mac, name, groups, endpoint, modelid, manufacturername, swbuildid, ritems) VALUES ('38', 'normal', '00:15:8d:00:05:20:e6:9e-01', 'Lamp Muurkast', '65520,11', '1', 'lumi.light.aqcn02', 'LUMI', '1.23', '{"attr/id":"38","attr/lastannounced":null,"attr/lastseen":"2022-02-12T15:57Z","attr/manufacturername":"LUMI","attr/modelid":"lumi.light.aqcn02","attr/name":"Lamp Muurkast","attr/swversion":"1.23","attr/type":"Color temperature light","attr/uniqueid":"00:15:8d:00:05:20:e6:9e-01","state/alert":"none","state/colormode":"hs","state/effect":"none","state/lift":null,"state/on":false,"state/open":null,"state/reachable":true,"state/x":29283,"state/y":26958}')
15:57:38:604 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('27', 'Kevin', 'ZHALightLevel', 'lumi.sensor_motion.aq2', 'LUMI', '00:15:8d:00:04:66:63:8e-01-0400', '20170627', '{"dark":false,"daylight":false,"lastupdated":"2022-02-12T15:57:22.269","lightlevel":13618,"lux":23}', '{"battery":100,"on":true,"reachable":true,"temperature":2100,"tholddark":12000,"tholdoffset":7000}', '{"d":263,"ep":1,"in":[0,1024,1],"p":260}', 'normal', '1', '2022-02-12T15:57Z', '')
15:57:38:605 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('260', 'LightLevel JH', 'ZHALightLevel', 'lumi.sen_ill.mgl01', 'LUMI', '04:cf:8c:df:3c:7d:13:30-01-0400', '20191118', '{"dark":false,"daylight":true,"lastupdated":"2022-02-12T15:57:38.326","lightlevel":21523,"lux":142}', '{"battery":100,"on":true,"reachable":true,"temperature":2500,"tholddark":12000,"tholdoffset":7000}', '{"d":262,"ep":1,"in":[0,1,1024],"p":260}', 'normal', '1', '2022-02-12T15:57Z', '2022-01-15T18:07:52Z')
15:57:38:606 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('26', 'Kevin', 'ZHAPresence', 'lumi.sensor_motion.aq2', 'LUMI', '00:15:8d:00:04:66:63:8e-01-0406', '20170627', '{"lastupdated":"2022-02-12T15:57:22.278","presence":true}', '{"battery":100,"duration":90,"on":true,"reachable":true,"temperature":2100}', '{"d":263,"ep":1,"in":[0,1030,1],"p":260}', 'normal', '1', '2022-02-12T15:57Z', '')
15:57:38:607 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('266', 'Lichtsensor Kevin', 'ZHALightLevel', 'lumi.sen_ill.mgl01', 'LUMI', '04:cf:8c:df:3c:78:c3:9e-01-0400', '20191118', '{"dark":false,"daylight":false,"lastupdated":"2022-02-12T15:57:31.611","lightlevel":13223,"lux":21}', '{"battery":100,"on":true,"reachable":true,"temperature":2500,"tholddark":12000,"tholdoffset":7000}', '{"d":262,"ep":1,"in":[0,1,1024],"p":260}', 'normal', '1', '2022-02-12T15:57Z', '')
15:57:38:608 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('279', 'Consumption 279', 'ZHAConsumption', 'TS011F', '_TZ3000_mraovvmm', '84:fd:27:ff:fe:ce:99:dc-01-0702', '', '{"consumption":3818,"lastupdated":"2022-02-12T15:53:35.084"}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:57Z', '')
15:57:38:609 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('280', 'Power 280', 'ZHAPower', 'TS011F', '_TZ3000_mraovvmm', '84:fd:27:ff:fe:ce:99:dc-01-0b04', '', '{"current":0,"lastupdated":"2022-02-12T15:57:16.291","power":0,"voltage":226}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:57Z', '')
15:57:38:610 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('269', 'Consumption 269', 'ZHAConsumption', 'TS011F', '_TZ3000_mraovvmm', '84:fd:27:ff:fe:ce:7b:ea-01-0702', '', '{"consumption":3131,"lastupdated":"2022-02-12T15:53:46.186"}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:57Z', '')
15:57:38:611 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('270', 'Power 270', 'ZHAPower', 'TS011F', '_TZ3000_mraovvmm', '84:fd:27:ff:fe:ce:7b:ea-01-0b04', '', '{"current":110,"lastupdated":"2022-02-12T15:57:31.621","power":13,"voltage":224}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:57Z', '')
15:57:38:612 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('287', 'Consumption 287', 'ZHAConsumption', 'TS011F', '_TZ3000_gjnozsaz', 'a4:c1:38:91:cb:9d:7c:e8-01-0702', '', '{"consumption":9,"lastupdated":"2022-02-12T15:55:09.460"}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:56Z', '')
15:57:38:613 DB sql exec REPLACE INTO sensors (sid, name, type, modelid, manufacturername, uniqueid, swversion, state, config, fingerprint, deletedState, mode, lastseen, lastannounced) VALUES ('288', 'Power 288', 'ZHAPower', 'TS011F', '_TZ3000_gjnozsaz', 'a4:c1:38:91:cb:9d:7c:e8-01-0b04', '', '{"current":299,"lastupdated":"2022-02-12T15:57:36.148","power":47,"voltage":227}', '{"on":true,"reachable":true}', '', 'normal', '2', '2022-02-12T15:57Z', '')