GZCGQ01LM "JINJA-transformation failed" message in openHAB Logfile, power_outage_count

[miwok72]

What happened?

Hello,

I am using zigbee2mqtt to include some xiaomi devices in ophenHAB, unfortunately since a while I am getting the following warning message flooding my openHAB logfile. I have 2 other devices that generate the same warning message (Xiaomi_MCCGQ11LM, Xiaomi_RTCGQ11LM).

2023-04-06 18:07:56.201 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_outage_count

It's just a warning message, but very annoying and it must have a cause? Since I don't know on which side the problem is, on zigbee2mqtt or on openHAB side, I'll start here. Thanks a lot!

firmwareVersion         2019www.
modelId             MiJia light intensity sensor (GZCGQ01LM)
deviceId            zigbee2mqtt_5F0x04cf8cdf3c7b3028
vendor              Xiaomi

OH MQTT Config Topic

sensor/0x04cf8cdf3c7b3028/battery
sensor/0x04cf8cdf3c7b3028/illuminance
sensor/0x04cf8cdf3c7b3028/illuminance_lux
sensor/0x04cf8cdf3c7b3028/linkquality
sensor/0x04cf8cdf3c7b3028/power_outage_count
sensor/0x04cf8cdf3c7b3028/voltage

Topic: homeassistant/sensor/0x04cf8cdf3c7b3028/power_outage_count/config

Payload: {"availability":[{"topic":"zigbee2mqttpi/bridge/state"},{"topic":"zigbee2mqttpi/Xiaomi_GZCGQ01LM_Helligkeit_01/availability"}],"availability_mode":"all","device":{"identifiers":["zigbee2mqtt_0x04cf8cdf3c7b3028"],"manufacturer":"Xiaomi","model":"MiJia light intensity sensor (GZCGQ01LM)","name":"Xiaomi_GZCGQ01LM_Helligkeit_01","sw_version":"2019\u0000www."},"enabled_by_default":true,"name":"Xiaomi_GZCGQ01LM_Helligkeit_01_power_outage_count","state_topic":"zigbee2mqttpi/Xiaomi_GZCGQ01LM_Helligkeit_01","unique_id":"0x04cf8cdf3c7b3028_power_outage_count_zigbee2mqttpi","value_template":"{{ value_json.power_outage_count }}"}

Topic: zigbee2mqttpi/Xiaomi_GZCGQ01LM_Helligkeit_01

Payload: {"battery":100,"illuminance":30705,"illuminance_lux":1176,"linkquality":94,"power_outage_count":null,"voltage":3000}

Payload for another device (Xiaomi_RTCGQ11LM): {"battery":100,"device_temperature":25,"illuminance":29,"illuminance_lux":29,"linkquality":123,"occupancy":true,"power_outage_count":36,"temperature":28,"voltage":3025}

What did you expect to happen?

The warning messages should not appear.

How to reproduce it (minimal and precise)

No response

Zigbee2MQTT version

1.30.3, 1.30.4, 1.31.0, 1.32.0

Adapter firmware version

20221226, 20230507

Adapter

Slaesh's CC2652RB

Debug log

No response

[gargamelonly]

Having the same problem with other devices too. Any clue as to how to resolve it?

Also with: [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json['update']['state']

{"availability":[{"topic":"zigbee2mqtt/bridge/state"}],"device":{"identifiers":["zigbee2mqtt_0x54c138f5267c045d"],"manufacturer":"TuYa","model":"Smart plug (with power monitoring) (TS011F_plug_1)","name":"wallplug2"},"device_class":"update","enabled_by_default":false,"entity_category":"diagnostic","json_attributes_topic":"zigbee2mqtt/wallplug2","name":"wallplug2 update available","payload_off":false,"payload_on":true,"state_topic":"zigbee2mqtt/wallplug2","unique_id":"0x54c138f5267c045d_update_available_zigbee2mqtt","value_template":"{{ value_json['update']['state'] == \"available\" }}"}

and: [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_on_behavior

{"availability":[{"topic":"zigbee2mqtt/bridge/state"}],"command_topic":"zigbee2mqtt/wallplug16A/set/power_on_behavior","device":{"identifiers":["zigbee2mqtt_0x60a423fffed2e99f"],"manufacturer":"TuYa","model":"Socket module (TS011F_socket_module)","name":"wallplug16A"},"entity_category":"config","icon":"mdi:power-settings","json_attributes_topic":"zigbee2mqtt/wallplug16A","name":"wallplug16A power on behavior","options":["off","previous","on"],"state_topic":"zigbee2mqtt/wallplug16A","unique_id":"0x60a423fffed2e99f_power_on_behavior_zigbee2mqtt","value_template":"{{ value_json.power_on_behavior }}"}

[gargamelonly]

Many more warnings: Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json['update']['state']

[apella12]

@gargamelonly ; Not an expert and have worked around my problem by avoiding the homeassistant option in zwave-js-ui (using this as zwave to mqtt for openhab) (now just using the zwave to mqtt option with the generic openhab mqtt option). Anyway based on my limited experimentation I think the original poster is dealing with "null". There is a section in the OH-addons that looks like this;

 bindings.put("value", value);
        try {
            JsonNode tree = new ObjectMapper().readTree(value);
            bindings.put("value_json", toObject(tree));
        } catch (IOException e) {
            // ok, then value_json is null...
        }

Another possibility is that Openhab has a problem dealing with anything besides value_json.value.

My problem, and it could be somewhat related to your last post, is the dealing with options "options":["off","previous","on"]. My options have a number "key" and use the value_json.value as the "key" and apparently that is not allowed. I opened an issue on the imported program, but there is likely a problem greater than I know https://github.com/HubSpot/jinjava/issues/1090

[miwok72]

Not just "null" values. See the payload for the device Xiaomi_RTCGQ11LM on my first post, which produces the same warning messages.

[apella12]

@miwok72 Well I'm not an expert, but between the null and the variations on value_json.value I'd tend to lean towards an openhab limitation. The only constructive comment I can make is that the warn message is not in the same class as the JINJA transformation. You could try openhab>log:set debug org.openhab.transform.jinja to see if there is more information.

[gargamelonly]

2023-07-16 18:20:56.931 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"child_lock":"UNLOCK","current":0,"energy":6.07,"indicator_mode":"off/on","linkquality":43,"power":0,"power_outage_memory":"restore","state":"ON","update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":232}' by the function '{{ value_json['update']['state'] == "available" }}'

2023-07-16 18:20:56.933 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in 'false'

2023-07-16 18:20:56.934 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"child_lock":"UNLOCK","current":0,"energy":6.07,"indicator_mode":"off/on","linkquality":43,"power":0,"power_outage_memory":"restore","state":"ON","update":{"installed_version":-1,"latest_version":-1,"state":null},"update_available":null,"voltage":232}' by the function '{{ value_json['update']['state'] }}'

2023-07-16 18:20:56.936 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json['update']['state']

2023-07-16 18:23:26.566 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"child_lock":"UNLOCK","current":0,"energy":22.87,"indicator_mode":"off/on","linkquality":58,"power":0,"power_outage_memory":"restore","state":"OFF","update":{"installed_version":192,"latest_version":192,"state":"idle"},"update_available":false,"voltage":232}' by the function '{{ value_json.indicator_mode }}'

2023-07-16 18:23:26.568 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in 'off/on'

2023-07-16 18:24:14.273 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":160,"state":"OFF"}' by the function '{{ value_json.power_on_behavior }}'

2023-07-16 18:24:14.279 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_on_behavior

[miwok72]

Xiaomi_GZCGQ01LM:

2023-07-16 20:47:11.356 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.linkquality }}'
2023-07-16 20:47:11.359 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '87'
2023-07-16 20:47:11.359 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.illuminance }}'
2023-07-16 20:47:11.361 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '0'
2023-07-16 20:47:11.361 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.illuminance_lux }}'
2023-07-16 20:47:11.363 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '0'
2023-07-16 20:47:11.364 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.power_outage_count }}'
2023-07-16 20:47:11.365 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_outage_count
2023-07-16 20:47:11.366 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.voltage }}'
2023-07-16 20:47:11.367 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '3000'
2023-07-16 20:47:11.369 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"battery":100,"illuminance":0,"illuminance_lux":0,"linkquality":87,"power_outage_count":null,"voltage":3000}' by the function '{{ value_json.battery }}'
2023-07-16 20:47:11.370 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '100'

[apella12]

So I hate to be the skunk at the picnic, but my untrained eye 2 of the three examples are related to a "null" value and the other is due to the missing parameter entirely.

[gargamelonly]

how do yo conclude from the log that it is related to "null" value ?

[apella12]

@gargamelonly I'm not an expert, but the "by the function" appears to return the value or string after the corresponding parameter in the expression. That is pretty clear with the debug example @miwok72 posted. The transformation handles all the items except the one that is null. Your first one is a little more iffy since I do not know for sure how '{{ value_json['update']['state'] }}' is supposed to be interpreted. My educated guess is that it is working on this segment "update":{"installed_version":-1,"latest_version":-1,"state":null} and reading the nested item "state" (ie null) within the "update" array. The second example fails because there is no power_on_behavior parameter in the array to be evaluated.

My suggestion is use your MQTT explorer to publish an appropriate (like 0 or "off") retained message to the topic with the null and see if that clears up the warning. I can't comment on whether these items should really be populated from the device during discovery or as a lookup from some database of devices, but putting a value or string there could be a workaround

[gargamelonly]

I searched MQTT explorer and I can't see the "null" value anywhere,

[apella12]

This is an area I have been working to understand with zwave-js-ui (not zigbeemqtt) for about 4-6 weeks, so buyer beware. Anyway, that said, the way I think this works is the homeassistant "config" "pulls data" from the other topics. Since the state topic is "zigbee2mqtt/wallplug2" what does an expanded view of that topic look like? I can see from the picture there are 14 topics. Null might be shown as ""

[gargamelonly]

What you write seems logical as I can see the null value in the other switch:

and:

Now I can't figure out how to update only the 'null' value as the 'state' parameter does not appear in the publish listed options. [edit] I manually added the update_available to false and it got overwritten as soon as the device sent an update. So the null value returned.

[gargamelonly]

An update: I think I found a temporary workaround for the 'null' value in the "update"-"state:" I used the zigbee2mqtt ota menu to manually check for OTA update and the "state" changed to "idle" and no more warnings in the log. Now I need to resolve the warning for the "power_on_behavior" 2023-07-19 22:58:54.062 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_on_behavior

[apella12]

Good insight to try the OTA update.

From the picture the power_on_behavior warning is on the Smart Switch. I see the note about three topics, but only two are in the JSON. What does the expansion of that topic look like? Again I would first try just adding it. That parameter is typically something like "ON", "OFF" or "LAST STATUS"

[gargamelonly]

I manually added to the "Smart Switch" the "power_on_behavior" parameter:

When checking the number of topics after adding it, the number now increased to 4. Strange.

Why does it initially looks for the "power_on_behavior" parameter if it does not exist anywhere?

{
  "availability": [
    {
      "topic": "zigbee2mqtt/bridge/state",
      "value_template": "{{ value_json.state }}"
    }
  ],
  "command_topic": "zigbee2mqtt/SmartSwitch/set",
  "device": {
    "identifiers": [
      "zigbee2mqtt_0xxxxxx"
    ],
    "manufacturer": "eWeLink",
    "model": "Smart light switch - 1 gang (ZB-SW01)",
    "name": "SmartSwitch",
    "sw_version": "1.0.3"
  },
  "name": "SmartSwitch",
  "payload_off": "OFF",
  "payload_on": "ON",
  "state_topic": "zigbee2mqtt/SmartSwitch",
  "unique_id": "0xxxxxx_switch_zigbee2mqtt",
  "value_template": "{{ value_json.state }}"
}

There is another switch which does expose this parameter:

{
  "availability": [
    {
      "topic": "zigbee2mqtt/bridge/state",
      "value_template": "{{ value_json.state }}"
    }
  ],
  "command_topic": "zigbee2mqtt/wallplug16A/set",
  "device": {
    "identifiers": [
      "zigbee2mqtt_0xyyyyyyyy"
    ],
    "manufacturer": "TuYa",
    "model": "Socket module (TS011F_socket_module)",
    "name": "wallplug16A"
  },
  "name": "wallplug16A",
  "payload_off": "OFF",
  "payload_on": "ON",
  "state_topic": "zigbee2mqtt/wallplug16A",
  "unique_id": "0xyyyyyyy_switch_zigbee2mqtt",
  "value_template": "{{ value_json.state }}"
}

However it is presented with these values:

{
  "linkquality": 160,
  "power_on_behavior": "on",
  "state": "OFF"
}

After both exist now the JINJA warning still prevails.

[apella12]

@gargamelonly _Why does it initially looks for the "power_onbehavior" parameter if it does not exist anywhere? I don't know. Maybe the homeassistant config is wrong for that device?

After both exist now the JINJA warning still prevails. What does the debug look like after the change? Did you set the value to RETAIN? Is it capital ON or just on?

[gargamelonly]

using debug I can see the warning is for the "smart switch" device:

2023-07-22 10:43:20.078 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":160,"state":"OFF"}' by the function '{{ value_json.power_on_behavior }}'

2023-07-22 10:43:20.082 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_on_behavior

2023-07-22 10:43:20.084 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":160,"state":"OFF"}' by the function '{{ value_json.linkquality }}'

2023-07-22 10:43:20.087 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '160'

2023-07-22 10:43:20.089 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":160,"state":"OFF"}' by the function '{{ value_json.state }}'

2023-07-22 10:43:20.093 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in 'OFF'

2023-07-22 10:43:54.151 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":156,"state":"OFF"}' by the function '{{ value_json.power_on_behavior }}'

2023-07-22 10:43:54.155 [WARN ] [t.generic.ChannelStateTransformation] - Executing the JINJA-transformation failed: An error occurred while transformation. UnknownTokenException: Unknown token found: value_json.power_on_behavior

2023-07-22 10:43:54.157 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":156,"state":"OFF"}' by the function '{{ value_json.linkquality }}'

2023-07-22 10:43:54.161 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in '156'

2023-07-22 10:43:54.163 [DEBUG] [.internal.JinjaTransformationService] - about to transform '{"linkquality":156,"state":"OFF"}' by the function '{{ value_json.state }}'

2023-07-22 10:43:54.167 [DEBUG] [.internal.JinjaTransformationService] - transformation resulted in 'OFF'

I tried using both "on" and "ON" and in retain mode. The error still appears.

[gargamelonly]

I think I figured out what is causing the Jinja errors in the log.

Initially when the switch was added into an openHAB Thing, through the auto detect Homeassistant discovery method, the Zigbee2MQTT specific device definition had a 'power_on_behavior' option. After some time it was discovered that this device cannot support it and the Zigbee2MQTT device was updated, with this parameter removed. However, the "Thing" definition from the old discovery still had the 'power_on_behavior' leftover item. To remove this leftover I simply deleted the Thing and re-discovered it, now with no 'power_on_behavior' item.

This solved it. No more warnings on Jinja errors for this parameter. So to sum-up, we still need to figure out how to deal with 'null' values.

[apella12]

@gargamelonly - Thanks for the shout-out on the OH forum, but you solved both of your two "null" problems yourself, once requesting an update (changing null to idle) and the other with a delete/rediscovery (eliminating a no longer supported topic). My idea of forcing a state onto a topic didn't work.

Based on that, my new idea for @miwok72 would be to cause a power outage on the device (maybe unplug?). That would increase the count from 'null' to '1' and eliminate the error.

At my level of knowledge not sure how the "null" can be eliminated for all cases since it could occur with both a missing topic and an empty value. Possibly the zigbee2mqtt could populate some device start up values with "0" or 'idle' etc. instead of empty. (example being the power_outage_count. From the forum discussion I see that null is allowed in a JSON string.

Anyway glad your warning are gone.

[github-actions[bot]]

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

[ccutrer]

Oh hey, this is coming from a Zigbee device! I'm getting the power_on_behavior warning in my openHAB logs, but I thought it was for a non-zigbee (or zwave) device. I'll try to look into this soon, and see how Home Assistant handles it. I suspect either Python's Jinja just treats missing keys as null, or it's silently swallowing errors about missing keys. Either way, openHAB should behave the same. That would be an openHAB issue, but zigbee2mqtt could likely work around it by formulating the transformation slightly differently.

[ccutrer]

Yes, Python just returns None:

>>> from jinja2 import Environment
>>> env = Environment()
>>> expr = env.compile_expression("value_json.power_on_behavior")
>>> value_json = json.loads("{}")
>>> expr(value_json=value_json)
>>> type(expr(value_json=value_json))
<class 'NoneType'>
>>> value_json = json.loads('{ "power_on_behavior": true }')
>>> expr(value_json=value_json)
True

Therefore it's a bug in either openHAB or Jinjava.