Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Problem]: Iluminize 5120.1100 wrong state #10409

Closed
Jogobo opened this issue Dec 28, 2021 · 26 comments
Closed

[Problem]: Iluminize 5120.1100 wrong state #10409

Jogobo opened this issue Dec 28, 2021 · 26 comments
Labels
problem Something isn't working stale Stale issues

Comments

@Jogobo
Copy link

Jogobo commented Dec 28, 2021

What happened?

Since the last update I have a problem with my dimmer. When I publish the payload '{"state":"ON"}' to the device the subscriber receives the following two messages:
{"state":"ON"}
{"brightness":254,"last_seen":"2021-12-28T16:25:29.267Z","linkquality":18,"state":"OFF"}

The device reacts as expected and the light turns on. Rules which check for a state change receive "ON" and immediately after that "OFF" from the long message. Thus resulting in performing the "OFF" action instead of "ON".

What did you expect to happen?

I would expect the get message to show the state which has been set before.

How to reproduce it (minimal and precise)

Just subscribe to the device and send the payload.

Zigbee2MQTT version

1.22.1

Adapter firmware version

20210708

Adapter

Slaesh's CC2652RB stick

Debug log

No debug log available

@Jogobo Jogobo added the problem Something isn't working label Dec 28, 2021
@Koenkk
Copy link
Owner

Koenkk commented Dec 29, 2021

Please provide the debug log of this.

See https://www.zigbee2mqtt.io/guide/usage/debug.html on how to enable debug logging.

@Jogobo
Copy link
Author

Jogobo commented Dec 29, 2021

z2m.log

The device is called mqtt_Dimmer01 (0x804b50fffebbf21f)

@Koenkk
Copy link
Owner

Koenkk commented Dec 29, 2021

Looks to be a home assistant issue, the on is directly published after the off, HA should use the latest message only.

Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.437Z zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":8,"manufacturerCode":null,"commandIdentifier":11},"Payload":{"cmdId":1,"statusCode":0},"Command":{"ID":11,"name":"defaultRsp","parameters":[{"name":"cmdId","type":32},{"name":"statusCode","type":32}]}},"address":3842,"endpoint":1,"linkquality":15,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'
Dec 29 18:39:47 jogolinux npm[5968]: �[32mZigbee2MQTT:info �[39m 2021-12-29 18:39:47: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-29T17:39:47.437Z","linkquality":15,"state":"OFF"}'
Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.439Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []
Dec 29 18:39:47 jogolinux npm[5968]: �[32mZigbee2MQTT:info �[39m 2021-12-29 18:39:47: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-29T17:39:47.437Z","linkquality":15,"state":"ON"}'
Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.642Z zigbee-herdsman:adapter:zStack:unpi:parser <-- [254,3,69,196,42,243,0,91]

@emontnemery could you check this?

@Jogobo
Copy link
Author

Jogobo commented Dec 31, 2021

As you can see below a state change of the device results in three messages:

Dec 31 11:51:51 jogolinux npm[7414]: ^[[32mZigbee2MQTT:info ^[[39m 2021-12-31 11:51:51: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-31T10:51:51.767Z","linkquality":24,"state":"OFF"}'
Dec 31 11:51:51 jogolinux npm[7414]: ^[[32mZigbee2MQTT:info ^[[39m 2021-12-31 11:51:51: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-31T10:51:51.767Z","linkquality":24,"state":"ON"}'

Message no. 2 and 3 have exactly the same timestamp.

I'm using openHAB for my smarthome and I have a rule which says "lower the blind in the bathroom when it's dark outside and the light turns on". Another rule says 'open the blind in the bathroom when the light is turned off".
The message of the publisher, which sends '{"state":"ON"}', results in a state change event in OH. The blinds start to lower.
Then message no. 2 results in a state change event to "OFF" which starts to open the blinds again and because of message no. 3 there is a state change to "ON" again. Until then the predicted blind height in OH is at target level so that message no. 3 does not result in lowering the blind to the target level again.

This was definitely different before 1.22.1 as the blind acted as expected.

@Koenkk
Copy link
Owner

Koenkk commented Dec 31, 2021

I see, I cannot explain the duplicate messages yet, could you share me your configuration.yaml? (with passwords removed)

@Jogobo
Copy link
Author

Jogobo commented Dec 31, 2021

Here you are...

configuration.yaml
homeassistant: false
permit_join: false
mqtt:
base_topic: zigbee2mqtt
server: mqtt://192.168....
user: unknown
password: secret
serial:
port: /dev/ttyUSB0
availability:
active:
timeout: 10
passive:
timeout: 1500
advanced:
pan_id: 6755
cache_state: true
channel: 11
log_level: info
log_output:
- console
network_key:
- some values
last_seen: ISO_8601
experimental:
output: json
ikea_ota_use_test_url: false
log_syslog:
app_name: Zigbee2MQTT
eol: /n
host: localhost
localhost: localhost
path: /dev/log
pid: process.pid
port: 123
protocol: tcp4
type: '5424'
frontend:
port: 8081
host: 192.168....
devices: devices.yaml
groups: groups.yaml
blocklist:

  • '0x00178801081e94e8'

devices.yaml

'0x7cb03eaa0a046444':
friendly_name: mqtt_Licht_Stall
retain: true
'0x8418260000dace3a':
friendly_name: mqtt_Licht_Blumenfenster
retain: true
'0x7cb03eaa00a7c301':
friendly_name: mqtt_Licht_Wohnzimmerfenster
retain: true
'0x84182600000f6bff':
friendly_name: mqtt_LichtKellertreppeMitte
retain: true
'0x84182600000fa2a9':
friendly_name: mqtt_LichtKellertreppeUnten
retain: true
'0x84182600000f890a':
friendly_name: mqtt_LichtKellergangMitte
retain: true
'0x7cb03eaa00a7bf26':
friendly_name: mqtt_Weihnachtsstern
retain: true
'0x7cb03eaa0a01301f':
friendly_name: mqtt_Switch_AP_Arbeitszimmer
retain: true
'0x84182600000d8729':
friendly_name: mqtt_Switch_Stehleuchte
retain: true
'0x7cb03eaa00b1ba9b':
friendly_name: mqtt_Switch_Lichterkette
retain: true
'0x84182600000d30f1':
friendly_name: mqtt_Switch_Sofalicht
retain: true
'0x7cb03eaa0a017172':
friendly_name: mqtt_Switch_AP_Schlafzimmer
retain: true
'0x84182600000a8e76':
friendly_name: mqtt_Switch_AP_Keller
retain: true
'0x7cb03eaa00a7bf62':
friendly_name: mqtt_Stehlampe_top
retain: true
'0x7cb03eaa00a7bfb8':
friendly_name: mqtt_Stehlampe_bottom
retain: true
'0x8418260000067b29':
friendly_name: mqtt_Licht_Flur_Eingang
retain: true
'0x00124b0018e1f6c6':
friendly_name: mqtt_Router
retain: true
'0x90fd9ffffedc6229':
friendly_name: mqtt_Licht_Kueche
'0x90fd9ffffed8c4e0':
friendly_name: mqtt_IKEA_Switch_Kueche
'0x7cb03eaa00a3c262':
friendly_name: mqtt_Switch_AP_Wohnzimmer
retain: true
'0x7cb03eaa00ad3467':
friendly_name: mqtt_Switch_Pavillon
retain: true
'0x7cb03eaa0a0451f8':
friendly_name: mqtt_Licht_Betriebsraum
'0x8418260000002c88':
friendly_name: mqtt_Kugelleuchte
'0x00124b0018e1f479':
friendly_name: mqtt_Router2
'0x804b50fffebbf21f':
friendly_name: mqtt_Dimmer01
debounce: 0
optimistic: true
'0x7cb03eaa0a041524':
friendly_name: mqtt_LichtKellertreppeOben
'0x804b50fffebfa91b':
friendly_name: mqtt_Dimmer03
'0x7cb03eaa00ad7266':
friendly_name: mqtt_DeckenlichtFlur
'0x7cb03eaa0a05923e':
friendly_name: mqtt_Tischlampe
'0x804b50fffe0a6acf':
friendly_name: mqtt_zbmini02
'0x00124b0023ad5e12':
friendly_name: mqtt_snzb03_02
'0x00124b0023ad9c75':
friendly_name: mqtt_snzb03_01
'0x00124b0023ac5b4e':
friendly_name: mqtt_snzb03_03
'0x842e14fffe655093':
friendly_name: mqtt_zbmini01
'0x804b50fffe08deab':
friendly_name: mqtt_zbmini03
'0x84182600000f79f3':
friendly_name: mqtt_LichtKellergang
'0x7cb03eaa00a35705':
friendly_name: mqtt_BildKueche_unten
'0x7cb03eaa00a90aed':
friendly_name: mqtt_BildKueche_oben
'0x7cb03eaa00a11647':
friendly_name: mqtt_Licht_Kuechenschrank
'0x8418260000dab3d6':
friendly_name: mqtt_Licht_Arbeitsflaeche
'0x000d6f000e05a06b':
friendly_name: mqtt_Motion_Stall
'0x7cb03eaa00a9b9a7':
friendly_name: mqtt_Pavillon_LED_2
'0x7cb03eaa00a9b956':
friendly_name: mqtt_Pavillon_LED_1
'0x000d6f000d12ff6a':
friendly_name: mqtt_Motion_KellertreppeOben
occupancy_timeout: 30
'0x000d6f000d9f68ea':
friendly_name: mqtt_SwitchBildKueche
'0x000d6f000d5793b6':
friendly_name: mqtt_SwitchSchrankKueche
'0x000d6f000e059937':
friendly_name: mqtt_Motion_Betriebsraum
'0x000d6f0011b414d8':
friendly_name: mqtt_4xSwitchBuero
'0x000d6f000e0592b3':
friendly_name: mqtt_Motion_Kellertreppe
'0xf0d1b8000014980b':
friendly_name: mqtt_DeckenlichtBuero
'0x7cb03eaa00a7c03a':
friendly_name: mqtt_Stehlampe_middle
'0x000d6f000d12fed3':
friendly_name: mqtt_Motion_Kellergang

@Koenkk
Copy link
Owner

Koenkk commented Jan 1, 2022

It maybe be due to the debounce: 0, please remove it from your devices.yaml.

@Jogobo
Copy link
Author

Jogobo commented Jan 1, 2022

Oh, that's just a leftover from some tests I did before I opened the issue. The settings were the same as with "mqtt_Dimmer03", which is the same type of device. A quick test showed the same result:
{"brightness":102,"last_seen":"2022-01-01T13:02:19.048Z","linkquality":21,"state":"OFF"} {"brightness":102,"last_seen":"2022-01-01T13:02:19.048Z","linkquality":21,"state":"ON"} {"brightness":102,"last_seen":"2022-01-01T13:02:29.526Z","linkquality":21,"state":"ON"} {"brightness":102,"last_seen":"2022-01-01T13:02:29.526Z","linkquality":21,"state":"OFF"} {"brightness":102,"last_seen":"2022-01-01T13:03:20.629Z","linkquality":24,"state":"OFF"}
Switching from "OFF" to "ON" and back to "OFF" results in two messages with same timestamp and different states.

@Jogobo
Copy link
Author

Jogobo commented Jan 1, 2022

Just did another test with a Sonoff ZBMINI. Turning it on and off again results in

{"last_seen":"2022-01-01T13:08:05.959Z","linkquality":21,"state":"ON"}
{"last_seen":"2022-01-01T13:08:07.740Z","linkquality":21,"state":"ON"}
{"last_seen":"2022-01-01T13:08:07.743Z","linkquality":21,"state":"ON"}
{"last_seen":"2022-01-01T13:08:07.743Z","linkquality":21,"state":"ON"}
{"last_seen":"2022-01-01T13:08:22.887Z","linkquality":21,"state":"OFF"}
{"last_seen":"2022-01-01T13:08:22.889Z","linkquality":21,"state":"OFF"}
{"last_seen":"2022-01-01T13:08:22.889Z","linkquality":21,"state":"OFF"}

At least all the states are correct but the number of messages seams way too many.

@Koenkk
Copy link
Owner

Koenkk commented Jan 1, 2022

Can you provide the debug log again now? Without it I cannot determine where these messages come from.

@Jogobo
Copy link
Author

Jogobo commented Jan 1, 2022

Test device is "mqtt_zbmini02"
z2m.log
.

@Koenkk
Copy link
Owner

Koenkk commented Jan 2, 2022

Just checked, it indeed provides 3 updates per state change:

  1. Comes from the device reporting the state change
  2. Comes from the command execution confirmation, this causes the last_seen to update -> published to MQTT (can be avoided by disabling last_seen)
  3. Comes from the optimistic state handling of z2m (since the command has been successfully executed it assumes the state chnaged) (can be avoided by setting optimistic: false for this device)

@Jogobo
Copy link
Author

Jogobo commented Jan 2, 2022

Thank you for your update. Just tested the Iluminize device with last_seen=disabled and I only get one message per state change. So it looks like it's all "last_seen" related.
When message no 2. is generated, shouldn't it reflect the state change from message no. 1 as well? Three messages in a row, all with the same state, do not bother openHAB as already the first message causes the state changed event.

What are the side effects of disabling last_seen? Will "availability" still work?

@Koenkk
Copy link
Owner

Koenkk commented Jan 2, 2022

What are the side effects of disabling last_seen? Will "availability" still work?

last_seen is just for adding last seen to the state, doesn't affect availability

@Jogobo
Copy link
Author

Jogobo commented Jan 3, 2022

So, is disabling "last_seen" just a workaround or the final solution?
As the Iluminize device sends "ON", "OFF", "ON" and the ZBMINI sends three times "ON" in a row, the behaviour of different devices is not consistent.

@Koenkk
Copy link
Owner

Koenkk commented Jan 3, 2022

So, is disabling "last_seen" just a workaround or the final solution?

It is not a workaround, you should decide for yourself if you want this option or not, but depending on the device this could produce an additional message.

As the Iluminize device sends "ON", "OFF", "ON"

could you provide me the debug log of this? (let me know if last seen was enabled or disabled in this log)

@Jogobo
Copy link
Author

Jogobo commented Jan 3, 2022

It's in the debug log from 5 days ago. Device is mqtt_Dimmer01 and "last_seen" was enabled. You quoted the log entries in your answer to the debug log.

@emontnemery
Copy link

@Koenkk do you still need me to check from a HA perspective?

@Koenkk
Copy link
Owner

Koenkk commented Jan 3, 2022

@emontnemery no, thanks!

@Jogobo

As the Iluminize device sends "ON", "OFF", "ON"

I don't see the ON, OFF, ON, just OFF, ON which seems to be correct in this case, I've annotated the log:

# Request received to turn on mqtt_Dimmer01
Dec 29 18:39:46 jogolinux npm[5968]: �[34mZigbee2MQTT:debug�[39m 2021-12-29 18:39:46: Received MQTT message on 'zigbee2mqtt/mqtt_Dimmer01/set' with data '{"state":"ON"}'
Dec 29 18:39:46 jogolinux npm[5968]: �[34mZigbee2MQTT:debug�[39m 2021-12-29 18:39:46: Publishing 'set' 'state' to 'mqtt_Dimmer01'

# On command is send
Dec 29 18:39:46 jogolinux npm[5968]: 2021-12-29T17:39:46.977Z zigbee-herdsman:controller:endpoint Command 0x804b50fffebbf21f/1 genOnOff.on({}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":false,"direction":0,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false})
...

# Acknowledge to the on command is received -> this causes the last seen to change -> published to MQTT
Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.437Z zigbee-herdsman:adapter:zStack:znp:AREQ <-- AF - incomingMsg - {"groupid":0,"clusterid":6,"srcaddr":3842,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":15,"securityuse":0,"timestamp":1723915,"transseqnumber":0,"len":5,"data":{"type":"Buffer","data":[8,8,11,1,0]}}
Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.437Z zigbee-herdsman:controller:log Received 'zcl' data '{"frame":{"Header":{"frameControl":{"frameType":0,"manufacturerSpecific":false,"direction":1,"disableDefaultResponse":false,"reservedBits":0},"transactionSequenceNumber":8,"manufacturerCode":null,"commandIdentifier":11},"Payload":{"cmdId":1,"statusCode":0},"Command":{"ID":11,"name":"defaultRsp","parameters":[{"name":"cmdId","type":32},{"name":"statusCode","type":32}]}},"address":3842,"endpoint":1,"linkquality":15,"groupID":0,"wasBroadcast":false,"destinationEndpoint":1}'

# State publish because of the acknowledge updated the last seen
Dec 29 18:39:47 jogolinux npm[5968]: �[32mZigbee2MQTT:info �[39m 2021-12-29 18:39:47: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-29T17:39:47.437Z","linkquality":15,"state":"OFF"}'
Dec 29 18:39:47 jogolinux npm[5968]: 2021-12-29T17:39:47.439Z zigbee-herdsman:adapter:zStack:unpi:parser --- parseNext []

# On commands succeeds so zigbee2mqtt assumes state changed (optimistic publish)
Dec 29 18:39:47 jogolinux npm[5968]: �[32mZigbee2MQTT:info �[39m 2021-12-29 18:39:47: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-29T17:39:47.437Z","linkquality":15,"state":"ON"}'

If you would disable last_seen the first STATE: OFF publish should be gone. (so only 1 publish with STATE: ON)

Note that you see different behaviour between the mqtt_Dimmer01 and the ZBMINI because they report in differently; the ZBMINI confirms its state with an additional message while mqtt_Dimmer01 doesn't.

@Jogobo
Copy link
Author

Jogobo commented Jan 3, 2022

Here is an example event log from openHAB:

2021-12-31 08:47:37.122 [vent.ItemStateChangedEvent] - TasterBad_1_PressShort changed from OFF to ON
2021-12-31 08:47:37.147 [ome.event.ItemCommandEvent] - Item 'mqtt_DimmerBad_OnOff' received command ON
2021-12-31 08:47:37.149 [nt.ItemStatePredictedEvent] - mqtt_DimmerBad_OnOff predicted to become ON
2021-12-31 08:47:37.173 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from OFF to ON
2021-12-31 08:47:37.531 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from ON to OFF
2021-12-31 08:47:37.545 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from OFF to ON

As you can see "TasterBad_1_PressShort" initiates to publish {"state":"ON"} to "mqtt_DimmerBad_OnOff" and then you see changing the state from "ON" to "OFF" and back to "ON" again.

z2m.log shows only two entries

Dec 31 08:47:37 jogolinux npm[7414]: Zigbee2MQTT:info  2021-12-31 08:47:37: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-31T07:47:37.522Z","linkquality":0,"state":"OFF"}'
Dec 31 08:47:37 jogolinux npm[7414]: Zigbee2MQTT:info  2021-12-31 08:47:37: MQTT publish: topic 'zigbee2mqtt/mqtt_Dimmer01', payload '{"brightness":254,"last_seen":"2021-12-31T07:47:37.522Z","linkquality":0,"state":"ON"}'

It looks like the (wrong) state "OFF" (first entry in z2m.log) is processed before the (right) state "ON" (2nd entry in z2m.log) in openHAB.
According to the rules behind the PressShort action openHAB sends "ON" to mqtt_DimmerBad_OnOff, which is a generic mqtt item in openHAB. openHAB should send the state change to mosquitto, which publishes the new state to all subscribers. z2m seems to receive the state change, but "answers", due to the implementation of "last_seen" with the old state "OFF" and then with the new state "ON". These "answers" to the state change, initiated by openHAB, lead to an "ON", "OFF", "ON" action in openHAB.

@Jogobo
Copy link
Author

Jogobo commented Jan 3, 2022

I found the openHAB event.log entries corresponding to your quotes. Looks like this:

2021-12-29 18:39:46.924 [vent.ItemStateChangedEvent] - TasterBad_1_PressShort changed from OFF to ON
2021-12-29 18:39:46.957 [ome.event.ItemCommandEvent] - Item 'mqtt_DimmerBad_OnOff' received command ON
2021-12-29 18:39:46.958 [nt.ItemStatePredictedEvent] - mqtt_DimmerBad_OnOff predicted to become ON
2021-12-29 18:39:46.971 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from OFF to ON
2021-12-29 18:39:47.449 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from ON to OFF
2021-12-29 18:39:47.462 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from OFF to ON
2021-12-29 18:39:48.925 [vent.ItemStateChangedEvent] - TasterBad_1_PressShort changed from ON to OFF

Koenkk wrote:
# Acknowledge to the on command is received -> this causes the last seen to change -> published to MQTT
This should either contain the new state or the payload should only be {"last_seen":"xxxxxxxxx"}. Updating last seen but sending the state being set before receiving the actual command seems a little bit confusing. Or you should at least update the documentation that "last_seen" updates do not always reflect the actual state of some devices.

@Koenkk
Copy link
Owner

Koenkk commented Jan 3, 2022

@Jogobo if you don't want to have the complete state send on every state update, you can set advanced: cache_state: false in configuration.yaml (see https://www.zigbee2mqtt.io/guide/configuration/mqtt.html#mqtt-behaviour)

@Jogobo
Copy link
Author

Jogobo commented Jan 5, 2022

Made some more tests with different settings for cache_state and last_seen. Seems that cache_state: false and last_seen: ISO_8601_local does the trick.
openHAB receives only one state change.

2022-01-05 15:49:42.903 [ome.event.ItemCommandEvent] - Item 'mqtt_DimmerBad_OnOff' received command ON
2022-01-05 15:49:42.942 [nt.ItemStatePredictedEvent] - mqtt_DimmerBad_OnOff predicted to become ON
2022-01-05 15:49:42.951 [vent.ItemStateChangedEvent] - mqtt_DimmerBad_OnOff changed from OFF to ON

Every press on the switch produces 2 messages

{"last_seen":"2022-01-05T15:49:59+01:00","linkquality":0}
{"last_seen":"2022-01-05T15:49:59+01:00","linkquality":0,"state":"OFF"}

@Jogobo
Copy link
Author

Jogobo commented Jan 17, 2022

Had to go back to cache_state: true and last_seen: disabled because OH log filled with "unrecognized command" messages. As different OH items subscribe to the same subject and filter the payload they are looking for, missing payloads lead to empty commands.

@github-actions
Copy link
Contributor

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

@github-actions github-actions bot added the stale Stale issues label Feb 17, 2022
@satter
Copy link

satter commented Apr 23, 2022

I am consistently running into this issue:

Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:24: Received MQTT message on 'zigbee2mqtt/0x7cb03eaa00ae5ff1/set' with data '{"state":"ON"}'
Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:24: Publishing 'set' 'state' to 'osram_plug1'
Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:24: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:24+00:00","linkquality":76,"state":"OFF","update":{"state":"idle"}}'
Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:24: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:24+00:00","linkquality":76,"state":"ON","update":{"state":"idle"}}'
Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:24: Received Zigbee message from 'osram_plug1', type 'attributeReport', cluster 'genOnOff', data '{"onOff":1}' from endpoint 3 with groupID 0
Apr 23 10:38:24 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:24: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:24+00:00","linkquality":76,"state":"ON","update":{"state":"idle"}}'
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:30: Received MQTT message on 'zigbee2mqtt/0x7cb03eaa00ae5ff1/set' with data '{"state":"OFF"}'
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:30: Publishing 'set' 'state' to 'osram_plug1'
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:30: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:30+00:00","linkquality":72,"state":"ON","update":{"state":"idle"}}'
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:30: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:30+00:00","linkquality":72,"state":"OFF","update":{"state":"idle"}}'
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:debug 2022-04-23 10:38:30: Received Zigbee message from 'osram_plug1', type 'attributeReport', cluster 'genOnOff', data '{"onOff":0}' from endpoint 3 with groupID 0
Apr 23 10:38:30 homie1 npm[320195]: Zigbee2MQTT:info  2022-04-23 10:38:30: MQTT publish: topic 'zigbee2mqtt/osram_plug1', payload '{"last_seen":"2022-04-23T10:38:30+00:00","linkquality":72,"state":"OFF","update":{"state":"idle"}}'

For me it started with upgrading z2m (1.22.2 -> 1.23.0) and hb (v1.3.9 -> v1.4.0)
Related issues

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
problem Something isn't working stale Stale issues
Projects
None yet
Development

No branches or pull requests

4 participants