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

Duplicated messages #649

Closed
lych opened this issue Dec 3, 2018 · 33 comments
Closed

Duplicated messages #649

lych opened this issue Dec 3, 2018 · 33 comments

Comments

@lych
Copy link

lych commented Dec 3, 2018

When I click a button (lumi.remote.b1acn), sometimes zigbee2mqtt produce more then one event

  zigbee2mqtt:info 2018-12-3 15:01:34 MQTT publish, topic: 'zigbee2mqtt/Button1', payload: '{"battery":99,"voltage":3025,"linkquality":0,"click":"single"}'
  zigbee2mqtt:info 2018-12-3 15:01:34 MQTT publish, topic: 'zigbee2mqtt/Button1', payload: '{"battery":99,"voltage":3025,"linkquality":0,"click":"single"}'
  zigbee2mqtt:info 2018-12-3 15:01:34 MQTT publish, topic: 'zigbee2mqtt/Button1', payload: '{"battery":99,"voltage":3025,"linkquality":0,"click":"single"}'
  zigbee2mqtt:info 2018-12-3 15:01:35 MQTT publish, topic: 'zigbee2mqtt/Button1', payload: '{"battery":99,"voltage":3025,"linkquality":0,"click":"single"}'

more often it happens when link quality is about 0.

The button produces a lot of Report Attributes commands in purpose to deliver them, but all of that commands have the same Sequence Number.
Is there a way to filter commands with the same Sequence Number?

@lych lych changed the title Duplicate messages Duplicated messages Dec 3, 2018
@MarsWarrior
Copy link

I have the same problem with my Aqara temp/humi/pressure and human body sensors.

Most of the times each message is send twice.

zigbee2mqtt:info 2018-12-3 21:35:22 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":49,"occupancy":false}' zigbee2mqtt:info 2018-12-3 21:35:22 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":49,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:35:51 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":44,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:35:51 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":42,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:35:56 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":49,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:35:56 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":49,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:36:07 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":55,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:36:07 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":55,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:04 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":52,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:04 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":49,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:10 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":60,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:10 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":54,"linkquality":60,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:36 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":53,"linkquality":60,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:36 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":53,"linkquality":60,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:54 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":53,"linkquality":57,"occupancy":true}' zigbee2mqtt:info 2018-12-3 21:37:54 MQTT publish, topic: 'common/gateway/zigbee2mqtt/0x00158d0002b71fdf', payload: '{"illuminance":53,"linkquality":57,"occupancy":true}'

@lych
Copy link
Author

lych commented Dec 4, 2018

Threre are a lot of cases when such behaviour doesn't produce any big problems, for instance, illuminance, occupancy, temperature and etc data and events have to be analysed by time anyway, but in some cases (for instance clicking not fixed button) such behaviour turns the automation system into a random number generator.

@Koenkk
Copy link
Owner

Koenkk commented Dec 5, 2018

@lych could you share your debug log? (set log_level debug https://github.com/Koenkk/zigbee2mqtt/wiki/Configuration)

@lych
Copy link
Author

lych commented Dec 5, 2018

https://pastebin.com/Zckx5zKb
Starting from 20:20:43 all messages were caused by one click.

@Koenkk
Copy link
Owner

Koenkk commented Dec 7, 2018

We need to figure out if the messages are send by the device them-self.

Could you sniff the packets from the button? (http://www.inzoolee.com/capture-zigbee-packets/)

@lych
Copy link
Author

lych commented Dec 7, 2018

@Koenkk I'm used to using zboss sniffer with wireshark, but if you want I can do it by folowing your link.
pcap file
dm1
dm2

Starting from packet 1642, I had clicked the button once and it sent 20 Report Attributes commands and all of them with Sequence number 45 in ZCL frame. There are a lot of such clicks in the dump. The button increments Sequence number each new click.

@Koenkk
Copy link
Owner

Koenkk commented Dec 9, 2018

@lych does this also happen with other lumi.remote.b1acn?

@lych
Copy link
Author

lych commented Dec 9, 2018

I don't know, I have only one, but it seems that my lumi.weather behaves the same way, as @MarsWarrior wrote above. It happens when the link is bad (link quality 0). I'll try to sniff the packets.

@lych
Copy link
Author

lych commented Dec 9, 2018

Although I haven't managed to catch the same behavior with lumi.weather, it is much more difficult to catch it because I cannot influence on the process of sending data directly, but it also sends a lot of packets with the same Sequence Number. Nonetheless, there is a difference. There are 3 different Sequence Numbers in each packet. In IEEE 802.15.4 part, in the Zigbee network layer data and in the Zigbee Cluster Library Frame.
According to the dump, in most cases, all three Sequence Numbers change simultaneously, but sometimes first two Sequence numbers change, but Sequence Number in ZCL frame remains unchanged (for instance packets 1642 and 1644 in the damp) . It seems that at this moment duplicated data appear.
It looks like something (dongle firmware? zigbee2mqtt?) drops the packets with the same Sequence Number in IEEE 802.15.4 part and in the Zigbee Network Layer Data, but doesn't do it for packets with the same Sequence Numbers in ZCL frame.

@Koenkk
Copy link
Owner

Koenkk commented Dec 10, 2018

@lych zigbee2mqtt doesn't do that, it's either the firmware or zigbee-shepherd who does this.

@lych
Copy link
Author

lych commented Dec 10, 2018

@Koenkk I'm not sure that my conclusions are correct because I'm still not familiar enough with the Zigbee protocol. If such packets have to be filtered, who shoud do it? I think it can't be dongle firmaware because it's too high level for it. Shoud I move this problem to zigbee-shepherd project?

@Koenkk
Copy link
Owner

Koenkk commented Dec 11, 2018

You can, but it will probably not be solved because it's not maintained anymore.

What I found strange is that this issue happens only to you, me and many other have these devices and they work without problems. I still think there is something wrong with your device.

@lych
Copy link
Author

lych commented Dec 11, 2018

It can be the button of course, and I'll check it when I get another one. But I think, I only one who has this problem just because it's quite difficult to notice. To have it, one needs to run by the button something noticable, like lighting, and one click have to invert its state and link quality have to be about 0. Only in this way this construction starts to work like a random stroboscope :)

@stale
Copy link

stale bot commented Feb 9, 2019

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the stale Stale issues label Feb 9, 2019
@viboux
Copy link

viboux commented Feb 12, 2019

I got the same issue with a recently flashed CC2531 USB stick with all the instructions. Everything seems to work well apart from that

Here is what happen when clicking on and off on a Philips Hue Remote paired with zigbee2mqtt (device id has been altered in the log for a bogus id).

A Xiaomi sensor is working allright (no duplicate) and all the pairing went smoothly.

  zigbee2mqtt:info 2019-2-12 00:44:01 Zigbee publish to device '0x0017777777777777', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:info 2019-2-12 00:44:01 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"OFF","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:01 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"OFF","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:01 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"OFF","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:25 MQTT publish: topic 'zigbee2mqtt/0x0017880102c134a9', payload '{"battery":100,"linkquality":73,"action":"on"}'
  zigbee2mqtt:info 2019-2-12 00:44:26 Zigbee publish to device '0x0017777777777777', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:info 2019-2-12 00:44:26 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"ON","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:26 Zigbee publish to device '0x0017777777777777', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - null
  zigbee2mqtt:info 2019-2-12 00:44:26 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"ON","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:26 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"ON","brightness":254}'
  zigbee2mqtt:info 2019-2-12 00:44:26 MQTT publish: topic 'zigbee2mqtt/0x0017777777777777', payload '{"state":"ON","brightness":254}'

@stale stale bot removed the stale Stale issues label Feb 12, 2019
@Koenkk
Copy link
Owner

Koenkk commented Feb 12, 2019

@viboux can you post your debug log (http://zigbee2mqtt.io/configuration/configuration.html)

@bbrendon
Copy link

bbrendon commented Feb 13, 2019

My cube started doing this. I'm pretty sure when I first set it up this wasn't happening. The volume on my TV started going crazy which is how I finally tracked this down.

I watched the MQTT data which shows one message using mosquitto_sub -v -t '#' . But for some reason two state changes are registered in HASS.

@viboux
Copy link

viboux commented Feb 13, 2019

@viboux can you post your debug log (http://zigbee2mqtt.io/configuration/configuration.html)

You mean by changing the log level to debug instead of info? Or doing more?

Here is my version number (firmware and zigbee2mqtt).
2019-2-12 00:56:58 - info: Starting zigbee2mqtt version 1.1.1 (commit #unknown)
2019-2-12 00:56:58 - info: Starting zigbee-shepherd
2019-2-12 00:57:00 - info: zigbee-shepherd started
2019-2-12 00:57:00 - info: Coordinator firmware version: '20190109'
2019-2-12 00:57:00 - info: Currently 3 devices are joined:

@Koenkk
Copy link
Owner

Koenkk commented Feb 13, 2019

@bbrendon your automation is probably wrong, you should use the MQTT trigger automation

@viboux yes, change log level to debug

@bbrendon
Copy link

bbrendon commented Feb 13, 2019

@Koenkk Okay, thanks, I would never have guessed. Just curious though, is this by design or is it a bug in HASS? I was under the impression the design idea was to us MQTT as a way to get the data integrated into HASS so it could be used like everything else. Thus once the data gets into HASS the MQTT portion is not used.

@Koenkk
Copy link
Owner

Koenkk commented Feb 13, 2019

@bbrendon it was a bug in has which has been fixed now (attribute updates didn't trigger a sensor state change).

@antst
Copy link

antst commented Mar 26, 2019

I have issue with duplicated messages, but this one if more than duplication.

zigbee2mqtt/study_light/set {"state": "OFF"} 
zigbee2mqtt/study_light {"state":"OFF","linkquality":76,"brightness":102,"color_temp":322,"color" {"x":0.433,"y":0.407}}
zigbee2mqtt/study_light {"state":"ON","linkquality":76,"brightness":102,"color_temp":322,"color":{"x":0.433,"y":0.407}}

Light is turned OFF. Always. But I always have this OFF/ON pattern. and HA assume it is back ON.
This is Xiaomi bulb, btw.

At the same time, with Xiaomi wired wall switches, it is OK, even duplicated 3 times.

zigbee2mqtt/entrance_switch/left/set OFF
zigbee2mqtt/entrance_switch {"linkquality":76,"state_right":"OFF","state_left":"OFF"}
zigbee2mqtt/entrance_switch {"linkquality":78,"state_right":"OFF","state_left":"OFF"}
zigbee2mqtt/entrance_switch {"linkquality":76,"state_right":"OFF","state_left":"OFF"}

@antst
Copy link

antst commented Mar 26, 2019

I installed dev branch and now it is even more interesting.

Issue with OFF/ON is fixed. For "OFF" I get single and correct reply. But for ON I get 3 messages. All of them correct though.

And for xiaomi switch I always have 3 messages, for both ON and OFF, all of them correct.

@antst
Copy link

antst commented Mar 26, 2019

If it matters, this is what I see in log

Mar 26 13:15:00 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:00 PM Zigbee publish to device '0x00158d000302df88', genOnOff - on - {} - {"manufSpec":0,"disDefaultRsp":0} - 2
Mar 26 13:15:00 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:00 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":65,"state_right":"OFF","state_left":"ON"}'
Mar 26 13:15:00 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:00 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":81,"state_right":"OFF","state_left":"ON"}'
Mar 26 13:15:00 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:00 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":81,"state_right":"OFF","state_left":"ON"}'




Mar 26 13:15:21 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:21 PM Zigbee publish to device '0x00158d000302df88', genOnOff - off - {} - {"manufSpec":0,"disDefaultRsp":0} - 2
Mar 26 13:15:21 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:21 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":81,"state_right":"OFF","state_left":"OFF"}'
Mar 26 13:15:21 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:21 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":81,"state_right":"OFF","state_left":"OFF"}'
Mar 26 13:15:22 rpi npm[3607]:   zigbee2mqtt:info 3/26/2019, 1:15:22 PM MQTT publish: topic 'zigbee2mqtt/entrance_switch', payload '{"linkquality":81,"state_right":"OFF","state_left":"OFF"}'

@Koenkk
Copy link
Owner

Koenkk commented Mar 26, 2019

@antst please provide the log_level: debug log: http://www.zigbee2mqtt.io/configuration/configuration.html

@nicolasbrailo
Copy link

I'm also seeing duplicated messages. Tested with Philips and Ikea lamps. Relevant log section:

4/20/2019, 9:40:59 AM - debug: Received MQTT message on 'zigbee2mqtt/Kitchen Counter - Right/set' with data '{"state": "ON", "brightness": 51}'
4/20/2019, 9:41:00 AM - info: Zigbee publish to device '0x0017880104b8c734', genLevelCtrl - moveToLevelWithOnOff - {"level":51,"transtime":0} - {"manufSpec":0,"disDefaultRsp":0} - null
4/20/2019, 9:41:00 AM - info: MQTT publish: topic 'zigbee2mqtt/Kitchen Counter - Right', payload '{"state":"ON","brightness":51,"linkquality":23}'
4/20/2019, 9:41:00 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genLevelCtrl","data":{"currentLevel":51,"remainingTime":0}}' of device 'LWB010' (0x0017880104b8c734) of endpoint 11
4/20/2019, 9:41:00 AM - info: MQTT publish: topic 'zigbee2mqtt/Kitchen Counter - Right', payload '{"state":"ON","brightness":51,"linkquality":34}'
4/20/2019, 9:41:00 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genLevelCtrl","data":{"currentLevel":51}}' of device 'LWB010' (0x0017880104b8c734) of endpoint 11
4/20/2019, 9:41:00 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genLevelCtrl","data":{"currentLevel":51}}' of device 'LWB010' (0x0017880104b8c734) of endpoint 11

Full log: https://pastebin.com/kK59DkK2

@Koenkk
Copy link
Owner

Koenkk commented Apr 22, 2019

This issue will be further addressed in #1309

@Koenkk Koenkk closed this as completed Apr 22, 2019
@nicolasbrailo
Copy link

Looking forward to #1309.
Are these messages coming from the device or from zigbee sheperd?

@Koenkk
Copy link
Owner

Koenkk commented Apr 22, 2019

The device.

@antst
Copy link

antst commented Apr 29, 2019

I guess those are duplicated messages received through different routers, aren’t they?

@bachoo786
Copy link

@Koenkk I have the same issue with my xiaomi cube. I have subscribed to the "zigbee2mqtt/xiaomi cube" topic and the message payload that I get is repeated twice but in the first one it doesn't contain the "action" . However in the second message which is very identical it does give you the action. Here is what is produced:

b'{"action":"slide","action_angle":null,"action_from_side":null,"action_side":null,"action_to_side":null,"battery":100,"linkquality":153,"side":5,"voltage":3065}'
b'{"action":"","action_angle":null,"action_from_side":null,"action_side":null,"action_to_side":null,"battery":100,"linkquality":153,"side":5,"voltage":3065}'

Is this a bug or?

@phoenixnghi
Copy link

same issue, I can make it work for the automations, but not the dashboard to get the current status, because the second message is null

Zigbee2MQTT:info  2021-11-04 23:52:03: MQTT publish: topic 'zigbee2mqtt/Aqara cube', payload '{"action":"flip90","action_angle":null,"action_from_side":3,"action_side":1,"action_to_side":1,"angle":-38.62,"battery":100,"from_side":3,"linkquality":141,"side":1,"to_side":1,"voltage":3035}'

Zigbee2MQTT:info  2021-11-04 23:52:03: MQTT publish: topic 'zigbee2mqtt/Aqara cube', payload '{"action":"","action_angle":null,"action_from_side":null,"action_side":null,"action_to_side":null,"angle":-38.62,"battery":100,"linkquality":141,"side":1,"voltage":3035}'

Zigbee2MQTT:info  2021-11-04 23:52:03: MQTT publish: topic 'zigbee2mqtt/Aqara cube/action', payload 'flip90'

@toudidel
Copy link

toudidel commented Jan 11, 2022

Same issue. I have all messages duplicated for each device in my zigbee network.

Example:

Zigbee2MQTT:info  2022-01-11 12:52:17: MQTT publish: topic 'zigbee2mqtt/lamp', payload '{"current":0,"energy":2.47,"linkquality":28,"power":0,"state":"ON","voltage":231}'                     
Zigbee2MQTT:info  2022-01-11 12:53:17: MQTT publish: topic 'zigbee2mqtt/lamp', payload '{"current":0,"energy":2.47,"linkquality":31,"power":0,"state":"ON","voltage":225}'

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

10 participants