deconz V2.25.3 - Signify LTW012 show ON (in phoscon) even though it is OFF

[ParanoidiordnA]

Does the issue really belong here?

• [X] I definitively want to report a bug within deCONZ or its REST-API

Is there already an existing issue for this?

• [X] I have searched the existing issues and there is none for the bug at hand

Describe the bug

After Updating from version 2.24.3 to version 2.25.3 i experienced that two (of two) Signify LTW012 (FW 1.108.7) light bulbs appear in phoscon as ON even though they aren't. Turning the devices OFF in phoscon doesn't help. After a short time phoscon shows the devices as ON again. Reverting back to 2.24.3 brings back normal behavior of the devices.

Steps to reproduce the behavior

Connect a Signify LTW012 to phoscon, use deconz 2.25.3, wait for a few seconds

Expected behavior

Same behavior of the devices as in deconz 2.24.3

Screenshots

No response

Environment

• Host system: Raspberry Pi
• Running method: Raspbian
• Firmware version: 26720700
• deCONZ version 2.25.3
• Device: ConBee II
• Do you use an USB extension cable: yes
• Is there any other USB or serial devices connected to the host system? NO

deCONZ Logs

No response

Additional context

No response

[ebaauw]

Could you please check what happens when:

• You read the attributes of the Hue Effects cluster in the GUI?
• You read the attributes of the On/Off cluster in the GUI?

If these don’t correct the state, please attach screenshots of these clusters.

[ParanoidiordnA]

I will check that if you can provide a little more information about where i can find - attributes of Hue Effects and On/Off cluster in the (deconz?) GUI as i am running deconz on a headless system and therefore i am not familiar with the GUI at all. Thanks.

[ParanoidiordnA]

Found it :-) Reading the attributes didn't solve the problem.

[ebaauw]

That confirms the light reports as off (and 25% brightness and ct value of 400), as would be expected.

My LTW012 (E14 candle) is (still?) on 1.108.5; I didn't realise there's a newer firmware, but looking at the screenshots, that part hasn't changed.

Does the GUI show the LTW012 as supported by DDF? Do you see any errors in the deCONZ log, when enabling ERROR, DDF, and JS in the debug view? What's the debug log when reading the Hue Effects cluster?

Just to be sure: did you check other API clients than Phoscon (to rule out browser cache issues)?

[SwoopX]

@ParanoidiordnA Please change the issue name to something more suited to describe what you want to report. It should allow the devs as well as other users to find and follow what's discussed here. Thanks! 🙂

[Mimiix]

@ParanoidiordnA Please change the issue name to something more suited to describe what you want to report. It should allow the devs as well as other users to find and follow what's discussed here. Thanks! 🙂

Done :)

[Touille]

I have same "issue" with LTW010 (I have only one) (the 3 LCT015 's are OK) . Both seem to be on 1.101.2 Firmware.

Environment Host system: Raspberry Pi Running method: Raspbian Firmware version: 26780700 deCONZ version 2.25.3 Device: RaspBee II Is there any other USB or serial devices connected to the host system? NO

It dosent botther me to much since IRL with the switches and the sensors, all seem to work OK

But software side , Phoscon App (web and mobile) and Homebridge (also google home) report this Light ON (when it OFF IRL) :

When I switching it OFF in this software's (Bulb is already OFF IRL), the attributes of the On/Off cluster in the GUI stay the same as the screenshoot from ParanoidiordnA above. Then, 15sec or so after, those software report this light ON again (The Light stay OFF IRL)

When switching if ON/OFF with real switch/sensor, those attributes of the On/Off cluster in the GUI change to the right stance.

In 2.24.3 (and bellow) I never have this

EDIT: Debug log when trying to play around (OFF/ON Software side and reading ON/OFF & Hue Effects Attributes) https://pastebin.com/rkrG7Cfa

[ParanoidiordnA]

Does the GUI show the LTW012 as supported by DDF? Do you see any errors in the deCONZ log, when enabling ERROR, DDF, and JS in the debug view? What's the debug log when reading the Hue Effects cluster?

Where can if find the information about DDF support? There are no error in the debug log

Just to be sure: did you check other API clients than Phoscon (to rule out browser cache issues)? The device also shows as ON in Apple Home.

[ebaauw]

The "good" new: I can reproduce the issue, for an LTW010 and for a LTW012 (ZLL white ambiance). But not for the LCT015 (ZLL white and color ambiance, gamut C). All three have the same firmware image, 0x010C, but different DDFs. Looking at the diff between those DDFs. I don't see anything that could cause the different behaviour.

Looking at the deCONZ log, when parsing the 0xFC03/0x0002 attribute for the white ambiance:

Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:791 APS-DATA.request id: 91, addrmode: 0x03, addr: 0x00178801029A114C, profile: 0x0104, cluster: 0xFC03, ep: 0x01 -> 0x0B queue: 0 len: 7 tx.options 0x00
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:791   asdu (length: 7): 140B103D000200
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:810 APS-DATA.confirm id: 91, status: 0x00 SUCCESS
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:810 APS-DATA.confirm request id: 91 -> erase from queue
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:829 APS-DATA.indication srcAddr: 0x9432, srcEp: 0x0B dstAddrMode: 2, profile: 0x0104, cluster: 0xFC03, lqi: 255, rssi: -30
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:829   asdu: 1c0b103d01020000410607000039a501
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:829 APS-DATA.request id: 91 erase from queue
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:830 DJS evaluate()
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/on')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetItemVal: state/on
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/bri')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/bri --> 57.000000
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/ct')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/ct --> 421.000000
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/colormode')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/colormode --> ct
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/effect')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetItemVal: state/on
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_GetResourceItem: -> R.item('state/effect')
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/on --> none
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:835 DJS result  false, memory peak: 286720 bytes
Feb  8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:835 00:17:88:01:02:9a:11:4c-0b/state/on expression: /* global R, ZclFrame */
Feb  8 11:28:15 pi6 deCONZ[2344780]: var on = R.item('state/on').val
Feb  8 11:28:15 pi6 deCONZ[2344780]: const attrid = ZclFrame.at(1) << 8 | ZclFrame.at(0)
...
Feb  8 11:28:17 pi6 deCONZ[2344780]: on
Feb  8 11:28:17 pi6 deCONZ[2344780]:  --> false
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:835 Websocket 127.0.0.1:43546 send message: {"attr":{"lastseen":"2024-02-08T10:28Z"},"e":"changed","id":"18","r":"lights","t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 130)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:836 Websocket 192.168.76.40:56769 send message: {"attr":{"lastseen":"2024-02-08T10:28Z"},"e":"changed","id":"18","r":"lights","t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 130)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:836 Websocket 127.0.0.1:43560 send message: {"attr":{"lastseen":"2024-02-08T10:28Z"},"e":"changed","id":"18","r":"lights","t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 130)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:837 Websocket 127.0.0.1:43546 send message: {"e":"changed","id":"18","r":"lights","state":{"on":true},"t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 110)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:837 Websocket 192.168.76.40:56769 send message: {"e":"changed","id":"18","r":"lights","state":{"on":true},"t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 110)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:837 Websocket 127.0.0.1:43560 send message: {"e":"changed","id":"18","r":"lights","state":{"on":true},"t":"event","uniqueid":"00:17:88:01:02:9a:11:4c-0b"} (ret = 110)
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:838 SC tick --> StateCallFunction
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:838 SC --> StateFinished
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:838 SC state change finished: 00:17:88:01:02:9a:11:4c-0b
Feb  8 11:28:17 pi6 deCONZ[2344780]: 11:28:15:839 SC state/on: not synced

So the FC03_state.js script returns false (as expected), but deCONZ sets on to true, looking at the web socket events. I don't understand why. The SC messages (especially "state/on: not synced") look suspicious to me. When looking at the white and color ambiance, the log only shows:

Feb  8 11:32:55 pi6 deCONZ[2344780]: on
Feb  8 11:32:55 pi6 deCONZ[2344780]:  --> false
Feb  8 11:32:55 pi6 deCONZ[2344780]: 11:32:54:859 SC --> StateFinished
Feb  8 11:32:55 pi6 deCONZ[2344780]: 11:32:54:859 SC state change finished: 00:17:88:01:04:34:2c:ff-0b
Feb  8 11:32:55 pi6 deCONZ[2344780]: 11:32:54:863 APS-DATA.confirm id: 66, status: 0x00 SUCCESS
Feb  8 11:32:55 pi6 deCONZ[2344780]: 11:32:54:863 APS-DATA.confirm request id: 66 -> erase from queue

[manup]

Feb 8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/on --> none

I haven't checked in detail, but is this right? Guess this tries to set a string to a boolean value in DJS_SetItemVal():

        else if (duk_is_string(ctx, 0))
        {
            duk_size_t out_len = 0;
            const char *str = duk_to_lstring(ctx, 0, &out_len);
            U_ASSERT(str);
            if (out_len)
            {
                DBG_Printf(DBG_JS, "%s: %s --> %s\n", __FUNCTION__, item->descriptor().suffix, str);
                ok = item->setValue(QString(QLatin1String(str, out_len)), ResourceItem::SourceDevice);
            }
            duk_pop(ctx); /* conversion result*/
        }

[manup]

Feb 8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/on --> none

Hmm not sure where this comes frrom, the script doesn't set Item.val nor R.item('state/on').val.

[ebaauw]

Feb 8 11:28:15 pi6 deCONZ[2344780]: 11:28:15:834 DJS_SetItemVal: state/on --> none

Missed that line before. Checked the log: it appears for the white ambiance lights, but not for the white and color ambiance. Not with other value (false, true, 0, 1) either. I would expect the difference to be caused by difference in DDF file, but I fail to detect a relevant difference.

[ebaauw]

Feeling a bit experimental, I hacked the DDF files, so LTW010 is exposed by light_zll_C.ddf, and the issue no longer appears?

Find the 10 differences in DDF:

$ diff light_zll_white_ambiance.json light_zll_C.json 
6a7,18
>     "$MF_PHILIPS",
>     "$MF_PHILIPS",
>     "$MF_PHILIPS",
>     "$MF_PHILIPS",
>     "$MF_PHILIPS",
>     "$MF_PHILIPS",
>     "$MF_SIGNIFY",
>     "$MF_SIGNIFY",
>     "$MF_SIGNIFY",
>     "$MF_SIGNIFY",
>     "$MF_SIGNIFY",
>     "$MF_SIGNIFY",
12,17c24,41
<     "LTW001",
<     "LTW01x",
<     "LTW012",
<     "LTW001",
<     "LTW01x",
<     "LTW012"
---
>     "LTW010",
>     "LCT010",
>     "LCT014",
>     "LCT015",
>     "LCT016",
>     "LCT011",
>     "LLC020",
>     "LST002",
>     "LCT012",
>     "LTW010",
>     "LCT010",
>     "LCT014",
>     "LCT015",
>     "LCT016",
>     "LCT011",
>     "LLC020",
>     "LST002",
>     "LCT012"
19c43
<   "product": "Hue white ambiance light",
---
>   "product": "Hue white and color ambiance light",
24c48
<       "type": "$TYPE_COLOR_TEMPERATURE_LIGHT",
---
>       "type": "$TYPE_EXTENDED_COLOR_LIGHT",
104a129,131
>           "name": "cap/color/ct/computes_xy"
>         },
>         {
110a138,161
>           "name": "cap/color/effects"
>         },
>         {
>           "name": "cap/color/gamut_type"
>         },
>         {
>           "name": "cap/color/xy/blue_x"
>         },
>         {
>           "name": "cap/color/xy/blue_y"
>         },
>         {
>           "name": "cap/color/xy/green_x"
>         },
>         {
>           "name": "cap/color/xy/green_y"
>         },
>         {
>           "name": "cap/color/xy/red_x"
>         },
>         {
>           "name": "cap/color/xy/red_y"
>         },
>         {
119a171,176
>           "name": "config/color/xy/startup_x"
>         },
>         {
>           "name": "config/color/xy/startup_y"
>         },
>         {
156a214,225
>           "name": "state/x",
>           "read": {
>             "fn": "none"
>           }
>         },
>         {
>           "name": "state/y",
>           "read": {
>             "fn": "none"
>           }
>         },
>         {
176a246,292
>         },
>         {
>           "name": "state/effect",
>           "values": [
>             [
>               "\"none\"",
>               "no effect is active"
>             ],
>             [
>               "\"colorloop\"",
>               "colorloop through hue values"
>             ],
>             [
>               "\"candle\"",
>               "candlelight dynamic effect"
>             ],
>             [
>               "\"fireplace\"",
>               "fireplace dynamic effect"
>             ],
>             [
>               "\"prism\"",
>               "prism dynamic effect"
>             ]
>           ],
>           "parse": {
>             "fn": "zcl:attr",
>             "ep": "0x0b",
>             "cl": "0x0300",
>             "at": "0x4002",
>             "eval": "if (Item.val === 'none' || Item.val === 'colorloop') Item.val = Attr.val ? 'colorloop' : 'none'"
>           },
>           "read": {
>             "fn": "none"
>           }
>         },
>         {
>           "name": "state/hue",
>           "read": {
>             "fn": "none"
>           }
>         },
>         {
>           "name": "state/sat",
>           "read": {
>             "fn": "none"
>           }

[ebaauw]

I noticed state/effect is missing from the white ambiance DDF, but these lights do support the candle effect. After adding that to light_zll_white_ambiance.ddf, the issue no longer appears?! WTF?!

[manup]

What confuses me is that why doesn't the script actually set the 'state/on' value by something like Item.val = on? It only returns on but doesn't set it.

[ebaauw]

Normally, the DDF wrapper sets the item to the script's return value, doesn't it?

EDIT No, it doesn't - I assumed that because of #7576. Apparently, that's caused by the same or similar magic as this issue?

[manup]

No, this is only used for "write" function to get a value to write (but not actually set it)

/*! A generic function to write ZCL attributes.
    The \p writeParameters is expected to contain one object (given in the device description file).

    { "fn": "zcl:attr", "ep": endpoint, "cl": clusterId, "mf": manufacturerCode, "at": attributeId, "dt": zclDataType, "eval": expression }

    - endpoint: the destination endpoint, use 0 for auto endpoint (from the uniqueid)
    - clusterId: string hex value
    - manufacturerCode: (optional) string hex value
    - attributeId: string hex value
    - zclDataType: string hex value
    - expression: to transform the item value to the attribute value

    Example: "write": {"fn": "zcl:attr", "cl": "0x0000", "mf": "0x11F5", "at": "0xff0d",  "dt": "0x20", "eval": "Item.val"}
 */

[ebaauw]

This is higher-level magic to me, but I now have a version of the DDF and the JS that seems to work for all Hue lights. Will create a PR shortly.

[ebaauw]

Oh, joy, a new value for mode. I think it's a bitmap, but that's for another time.

Also note that you cannot set state/effect through the API (as the legacy code only supports state/effect for color lights with colorloop). That's why I left it out of the DDF for now. It will reflect the value when set though the GUI, though.

[ParanoidiordnA]

That's great. Thanks for digging through the code and providing a bug fix.

[manup]

@ParanoidiordnA I'm building a test version with the new fix, would be cool if you can try it in your setup. Do you have a 32-bit or 64-bit Raspbian?

[manup]

32-bit armhf test version with the applied fix can be found here http://deconz.dresden-elektronik.de/raspbian/beta/deconz_2.25.3_07714f-debian_armhf.deb

[ParanoidiordnA]

@ParanoidiordnA I'm building a test version with the new fix, would be cool if you can try it in your setup. Do you have a 32-bit or 64-bit Raspbian?

It's a 64bit Raspbian i'm using.

[manup]

Ok I'm compiling a version for 64-bit takes a sec.

http://deconz.dresden-elektronik.de/debian/beta/deconz_2.25.3_07714f-debian_arm64.deb

[Helox]

Same behaviour on my LTW001 and LTW010 lamps indeed.

[Touille]

32-bit armhf test version with the applied fix can be found here http://deconz.dresden-elektronik.de/raspbian/beta/deconz_2.25.3_07714f-debian_armhf.deb

That fixed it for me. Thanks you

[ParanoidiordnA]

Ok I'm compiling a version for 64-bit takes a sec.

http://deconz.dresden-elektronik.de/debian/beta/deconz_2.25.3_07714f-debian_arm64.deb

Bug fixed. Works like a charm :-)

[00lex]

LTW010@FW1.101.2 and 64bit arm works again. thank you

[mwicki]

LTW012@FW1.88.1 and 32bit armhf works again. thank you

[manup]

Thanks everyone for testing, big :+1: The fix has now been released in v2.26.0-beta with the plan to make it stable as v2.26.1 with no further changes this week.