search

Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
11.76k stars 1.64k forks source link

Testing: reporting #1064

Closed Koenkk closed 4 years ago

Koenkk commented 5 years ago

Reporting is a new feature which is currently only available in the dev branch. When reporting is enabled, the device will report their state changes to zigbee2mqtt. This is especially handy when the state of a bulb is changed by e.g. a remote or via groups.

To enable report, add the following to your configuration.yaml:

advanced:
  report: true

As reporting is a feature of the device, not all devices may support this.

Current findings

milakov commented 5 years ago

Hi!

Gledopto GL-B-007Z:

Changing color temperature triggers this (along with actual ct of the bulb changing):

zigbee2mqtt:error 2019-2-10 22:06:26 No converter available for 'color_temp' (166)

Changing brightness doesn't trigger anything in the logs (but the brightness of the physical bulb actually changes, HA still thinks the brightness is unchanged).

Koenkk commented 5 years ago

@milakov should be fixed in the latest dev branch, if not, please open a separate issue as this is not related to this issue.

sylarevan commented 5 years ago

Just tried with a group of two Hue bulbs. Changing the state (ON or OFF) of the group does not report the individual change of state of each bulb. Logs in debug mode are here.

JumpmanJunior commented 5 years ago

I tried to activate reporting for a Philips and a Ikea bulb. But when I control the bulbs with a bound Philips dimmer switch the status changes are not reported. Here is the log for the Ikea bulb:

2019-2-10 22:58:08 - debug: Setup reporting for 0x000d6ffffe1df5f5 - genOnOff - onOff 2019-2-10 22:58:09 - debug: Setup reporting for 0x000d6ffffe1df5f5 - genLevelCtrl - currentLevel 2019-2-10 22:58:09 - debug: Successfully setup reporting for 0x000d6ffffe1df5f5 - genOnOff - onOff 2019-2-10 22:58:09 - debug: Successfully setup reporting for 0x000d6ffffe1df5f5 - genLevelCtrl - currentLevel 2019-2-10 22:58:09 - debug: Setup reporting for 0x000d6ffffe1df5f5 - lightingColorCtrl - currentX 2019-2-10 22:58:09 - debug: Successfully setup reporting for 0x000d6ffffe1df5f5 - lightingColorCtrl - currentX 2019-2-10 22:58:09 - debug: Setup reporting for 0x000d6ffffe1df5f5 - lightingColorCtrl - currentY 2019-2-10 22:58:09 - debug: Successfully setup reporting for 0x000d6ffffe1df5f5 - lightingColorCtrl - currentY

way2many commented 5 years ago

I tested reporting of two Tradfri GU10 in my hallway this morning. I switched them off with the wire switch (220V) and put them back on. This is the log:

2/12/2019, 6:19:55 AM - debug: Saving state to file /app/data/state.json 2/12/2019, 6:21:53 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x90fd9ffffe1a7413"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe1a7413) 2/12/2019, 6:21:53 AM - debug: Setup reporting for 0x90fd9ffffe1a7413 - genOnOff - onOff 2/12/2019, 6:21:53 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x90fd9ffffe2a3f57"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe2a3f57) 2/12/2019, 6:21:54 AM - debug: Setup reporting for 0x90fd9ffffe1a7413 - genLevelCtrl - currentLevel 2/12/2019, 6:21:54 AM - debug: Successfully setup reporting for 0x90fd9ffffe1a7413 - genOnOff - onOff 2/12/2019, 6:21:54 AM - debug: Successfully setup reporting for 0x90fd9ffffe1a7413 - genLevelCtrl - currentLevel 2/12/2019, 6:21:54 AM - debug: Setup reporting for 0x90fd9ffffe2a3f57 - genOnOff - onOff 2/12/2019, 6:21:54 AM - debug: Successfully setup reporting for 0x90fd9ffffe2a3f57 - genOnOff - onOff 2/12/2019, 6:21:54 AM - debug: Setup reporting for 0x90fd9ffffe2a3f57 - genLevelCtrl - currentLevel 2/12/2019, 6:21:54 AM - debug: Successfully setup reporting for 0x90fd9ffffe2a3f57 - genLevelCtrl - currentLevel 2/12/2019, 6:21:55 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:56 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:56 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:57 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:57 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:59 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:59 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe1a7413"' 2/12/2019, 6:21:59 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x90fd9ffffe1a7413"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe1a7413) 2/12/2019, 6:21:59 AM - info: Device incoming... 2/12/2019, 6:21:59 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}' 2/12/2019, 6:21:59 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe1a7413) 2/12/2019, 6:22:01 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:01 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:01 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:02 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:02 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:03 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:03 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:03 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:04 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:04 AM - debug: Received zigbee message of type 'devInterview' with data '"0x90fd9ffffe2a3f57"' 2/12/2019, 6:22:04 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x90fd9ffffe2a3f57"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe2a3f57) 2/12/2019, 6:22:04 AM - info: Device incoming... 2/12/2019, 6:22:04 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}' 2/12/2019, 6:22:04 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TRADFRI bulb GU10 W 400lm' (0x90fd9ffffe2a3f57) 2/12/2019, 6:24:55 AM - debug: Saving state to file /app/data/state.json

I have now multiple questions:

As I'm unable to bind my Hue Dimmer Switch to my Hue suspension Fair I cannot test the reporting function on those one.

nanosonde commented 5 years ago

I am also trying to achieve the same. I have a TRADFRI remote and TRADFRI driver paired to zigbee2mqtt. I have found out the group ID of the remote by sniffing. Then I have created a group with this ID and added the TRADFRI driver to this group. I can successfully control the driver with the remote and z2m.

The reporting configuration seems to have worked:

  zigbee2mqtt:debug 2/13/2019, 1:45:38 PM Setup reporting for 0x000d6ffffe2cxxxx - genOnOff - onOff
  zigbee2mqtt:debug 2/13/2019, 1:45:38 PM Successfully setup reporting for 0x000d6ffffe2cxxxx - genOnOff - onOff
  zigbee2mqtt:debug 2/13/2019, 1:45:38 PM Setup reporting for 0x000d6ffffe2cxxxx - genLevelCtrl - currentLevel
  zigbee2mqtt:debug 2/13/2019, 1:45:38 PM Successfully setup reporting for 0x000d6ffffe2cxxxx - genLevelCtrl - currentLevel

However, I do not get any reports in z2m if it is controlled by the remote.

nanosonde commented 5 years ago

I am not seeing any attribute reports with the sniffer either. So is it the report configuration which did not work properly although it claims success?

nanosonde commented 5 years ago

From the ZCL Configure Reporting Message I see that there is a min interval of 1 and a max interval of 3600. 3600s would be 1h. So how does the device choose which to use? Is it possible to lower the value to 10s and see what happens?

Of course I would expect that it immediately sends a changed state, but I do not how this reporting is meant to work in detail.

Koenkk commented 5 years ago

@nanosonde just change https://github.com/Koenkk/zigbee2mqtt/blob/dev/lib/extension/reporting.js#L12 to 10 .

nanosonde commented 5 years ago

@Koenkk I have changed it to 10s and verified with the sniffer that this is sent over the wire. Unfortunately, it does not work too.

nanosonde commented 5 years ago

@Koenkk Somewhere in the deconz-plugin issues I have read that reporting for a TRADFRI device(?) only worked when it is read back. I am not absolutely sure anymore.

nanosonde commented 5 years ago

Got it working. I have disabled the generic reporting setup using "report: true". Instead I have changed device.js for the 10W dimmer similiar to the TRADFRI power outlet.

    {
        zigbeeModel: ['TRADFRI transformer 10W', 'TRADFRI Driver 10W'],
        model: 'ICPSHC24-10EU-IL-1',
        vendor: 'IKEA',
        description: 'TRADFRI driver for wireless control (10 watt)',
        //extend: generic.light_onoff_brightness,
        fromZigbee: [fz.ignore_onoff_change, fz.state],
        toZigbee: [tz.on_off],
        configure: (ieeeAddr, shepherd, coordinator, callback) => {
            const device = shepherd.find(ieeeAddr, 1);
            const cfg = {direction: 0, attrId: 0, dataType: 16, minRepIntval: 0, maxRepIntval: 1000, repChange: 0};
            const actions = [
                (cb) => device.bind('genOnOff', coordinator, cb),
                (cb) => device.foundation('genOnOff', 'configReport', [cfg], foundationCfg, cb),
            ];

            execute(device, actions, callback);
        },
    },

This way the driver immediately reports state changes.

nanosonde commented 5 years ago

@Koenkk Maybe I am missing something, but is the binding to the coordinator missing if reports are enabled using the generic mechansim? Or is this only required for TRADFRI devices?

https://github.com/Koenkk/zigbee2mqtt/blob/c9c599b60b709d897eb12286cdd57eb5214f0eb1/lib/extension/reporting.js#L43

There is no binding to the coordinator happening as it is done as show in my previous comment.

nanosonde commented 5 years ago

BTW: It looks like this with the above code change:

  zigbee2mqtt:debug 2/13/2019, 7:10:02 PM Received zigbee message of type 'cmdToggle' with data '{"cid":"genOnOff","data":{}}' of device 'TRADFRI remote control' (0xd0cf5efffe0bxxxx)
  zigbee2mqtt:info 2/13/2019, 7:10:02 PM MQTT publish: topic 'zigbee2mqtt/ikea_remotecontrol', payload '{"action":"toggle","linkquality":10,"last_seen":"2019-02-13T19:10:02.922Z","elapsed":5628497}'
  zigbee2mqtt:debug 2/13/2019, 7:10:02 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'TRADFRI transformer 10W' (0x000d6ffffe2cyyyy)
  zigbee2mqtt:info 2/13/2019, 7:10:02 PM MQTT publish: topic 'zigbee2mqtt/ikea_driver', payload '{"state":"ON","last_seen":"2019-02-13T19:10:02.955Z","linkquality":7,"elapsed":628194}'
Koenkk commented 5 years ago

@nanosonde I've also added the binding, meaning it should be the same as your custom configure now. Can you factory reset/re-pair the device and verify that it works with report: true?

nanosonde commented 5 years ago

@Koenkk I have tested latest dev and seems to be working now as with the custom configure. As I did a complete ./update.sh I experience an error now concerning the remote control:

  zigbee2mqtt:debug 2/13/2019, 8:42:05 PM Coordinator is already in group '611'
  zigbee2mqtt:error 2/13/2019, 8:42:05 PM Failed to apply coordinator group for IKEA TRADFRI remote control (0xd0cf5efffe0bxxxx)
  zigbee2mqtt:debug 2/13/2019, 8:42:05 PM Coordinator is already in group '99'

Did you change anything here? This was working before. Group ID 611 is correct. Why is the coordinator already in group 611? Is it from my testgroup under "groups" in the configuration with the same ID to which I have added my tradfri driver?

If I remove "coordinator_group" from the device config then this error is gone and I also receive the reports from button pushes.

BTW: Neither the driver nor the remote control need to be put close to the coordinator to pair them. The remote control just needs the 4-button-press sequence for factory reset which also restarts pairing (without touchlink). The driver just needs a short press with a paperclip to factory reset and restart pairing.

nanosonde commented 5 years ago

@Koenkk I have tested latest dev and seems to be working now as with the custom configure. As I did a complete ./update.sh I experience an error now concerning the remote control:

  zigbee2mqtt:debug 2/13/2019, 8:42:05 PM Coordinator is already in group '611'
  zigbee2mqtt:error 2/13/2019, 8:42:05 PM Failed to apply coordinator group for IKEA TRADFRI remote control (0xd0cf5efffe0bxxxx)
  zigbee2mqtt:debug 2/13/2019, 8:42:05 PM Coordinator is already in group '99'

Ok, I will answer that by myself after studying the code. So actually this is NOT a failure, but it is just as the previous message tells it: the ZDO of the coordinator already has the group added. So this is a bit misleading and not a real failure.

Koenkk commented 5 years ago

@nanosonde you are right, fixed.

Koenkk commented 5 years ago

Groups will now also report their state (on zigbee2mqtt/[GROUP_FRIENDLY_NAME). (dev branch)

dreimer1986 commented 5 years ago 
  zigbee2mqtt:error 2019-2-15 10:15:42 Failed to setup reporting for 0x84182600000b8298 - lightingColorCtrl - currentX - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:error 2019-2-15 10:15:44 Failed to setup reporting for 0x84182600000b79b7 - genLevelCtrl - currentLevel - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:warn 2019-2-15 10:15:45 Failed to configure Motion (0x000d6f000e059aae) ('Error: AF data request fails, status code: 240. MAC transaction expired.') (attempt #1)
  zigbee2mqtt:warn 2019-2-15 10:15:45 This can be ignored if the device is working properly
  zigbee2mqtt:error 2019-2-15 10:15:45 Failed to setup reporting for 0x7cb03eaa00a1184a - lightingColorCtrl - currentX - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:error 2019-2-15 10:15:46 Failed to setup reporting for 0x84182600000b743a - genOnOff - onOff - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b743a - lightingColorCtrl - colorTemperature - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b743a - genLevelCtrl - currentLevel - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b83ef - genOnOff - onOff - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b83ef - genLevelCtrl - currentLevel - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b743a - lightingColorCtrl - currentY - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  zigbee2mqtt:error 2019-2-15 10:15:47 Failed to setup reporting for 0x84182600000b743a - lightingColorCtrl - currentX - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  zigbee2mqtt:error 2019-2-15 10:15:48 Failed to setup reporting for 0x8418260000ca9270 - lightingColorCtrl - currentY - (Error: AF data request fails, status code: 233. MAC no ack.)
  zigbee2mqtt:error 2019-2-15 10:15:50 Failed to setup reporting for 0x7cb03eaa00a1184a - genLevelCtrl - currentLevel - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)

I added reporting to all my bulbs, in a group or not. Reporting does not work, but on startup you see this after it reconnected to all Zigbee devices. Do I have to repair all my bulbs to make it work?

EDIT: Debug loglevel: https://h.kremowka.xyz/etayakilox.coffeescript

Koenkk commented 5 years ago

@dreimer1986 can you control the bulb individually (turn on/off)?

alinelena commented 5 years ago

@Koenkk i get he same error as @dreimer1986 

  2/16/2019, 8:21:25 AM - debug: Setup binding for 0x000b57fffeb0c77e - genOnOff
  2/16/2019, 8:21:25 AM - debug: Setup reporting for 0x000b57fffeb0c77e - genOnOff - onOff
  2/16/2019, 8:21:25 AM - debug: Setup binding for 0x000b57fffeb0c77e - genLevelCtrl
  2/16/2019, 8:21:25 AM - debug: Setup reporting for 0x000b57fffeb0c77e - genLevelCtrl - currentLevel
)>2/16/2019, 8:21:25 AM - error: Failed to setup reporting for 0x000b57fffeb0c77e - genOnOff - onOff - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.)
  2/16/2019, 8:21:25 AM - debug: Setup binding for 0x000b57fffeb24cb3 - genOnOff
  2/16/2019, 8:21:26 AM - debug: Setup reporting for 0x000b57fffeb24cb3 - genOnOff - onOff
  2/16/2019, 8:21:26 AM - debug: Setup binding for 0x000b57fffeb24cb3 - genLevelCtrl
  2/16/2019, 8:21:26 AM - error: Failed to setup reporting for 0x000b57fffeb0c77e - genLevelCtrl - currentLevel - (Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network

much later I get a binding success message for both bulbs here. nothing more about reporting except the error. However reporting works and I can control them individually too or via the group.

I am on this

  2/16/2019, 8:21:21 AM - info: Starting zigbee2mqtt version 1.1.1 (commit #577bb0d)

I think that somehow one sets reporting too early

dreimer1986 commented 5 years ago

@Koenkk yes, controlling any of the bulbs works fine. Only reporting is not and the log fills a bit more when activated.

alinelena commented 5 years ago

@dreimer1986 this is what is in my log

2/16/2019, 4:01:38 PM - info: MQTT publish: topic 'zigbee2mqtt/bedroom_lights', payload '{"state":"OFF","brightness":255}'
2/16/2019, 4:01:38 PM - debug: Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'TRADFRI bulb E26 W opal 1000lm' (0x000b57fffeb0c77e)
2/16/2019, 4:01:38 PM - info: MQTT publish: topic 'zigbee2mqtt/ikea_bedroom_1', payload '{"state":"OFF","linkquality":49,"brightness":254}'
2/16/2019, 4:01:38 PM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'TRADFRI bulb E26 W opal 1000lm' (0x000b57fffeb0c77e)
2/16/2019, 4:01:38 PM - info: MQTT publish: topic 'zigbee2mqtt/ikea_bedroom_1', payload '{"state":"OFF","linkquality":49,"brightness":254}'
2/16/2019, 4:01:38 PM - debug: Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'TRADFRI bulb E26 W opal 1000lm' (0x000b57fffeb24cb3)
2/16/2019, 4:01:38 PM - info: MQTT publish: topic 'zigbee2mqtt/ikea_bedroom_2', payload '{"state":"OFF","linkquality":15,"brightness":254}'
2/16/2019, 4:01:38 PM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'TRADFRI bulb E26 W opal 1000lm' (0x000b57fffeb24cb3)
2/16/2019, 4:01:38 PM - info: MQTT publish: topic 'zigbee2mqtt/ikea_bedroom_2', payload '{"state":"OFF","linkquality":15,"brightness":254}'

annoying bit is the messages are reported twice

dreimer1986 commented 5 years ago

Nope, no report over here. Will repair the devices later these days. Maybe this finally fixes that and maybe my Smart+ Motion sensor to not only send me temperature information, but MOTION too ^^

Koenkk commented 5 years ago

@jbmbn greatly helped in improving the reporting functionality.

This is not configured per device anymore, but a global setting now, see OP.

BudBundi commented 5 years ago

It seems that GL-S-007Z - Gledopto Smart RGBW GU10 doesn't support reporting, no report after change over remote or homeassistant. Also I see this error in log: zigbee2mqtt:info 2/27/2019, 5:59:09 PM Zigbee publish to device '0x00124b001b6ae5e4', genOnOff - read - [{"attrId":0}] - {"manufSpec":0,"disDefaultRsp":0} - null zigbee2mqtt:error 2/27/2019, 5:59:39 PM Zigbee publish to device '0x00124b001b6ae5e4', genOnOff - read - [{"attrId":0}] - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: Timed out after 30000 ms

Same for GL-C-008 - Gledopto Zigbee LED controller RGB + CCT / RGBW / WWCW / Dimmer

JumpmanJunior commented 5 years ago

I have tried to setup reporting with the newest dev version. I am controlling a Hue bulb with a bound Hue dimmer switch. But the bulb only reports ons and offs but no brightness changes.

2019-3-1 21:21:57 - debug: Setup reporting for 0x00178801026cd5d3 - genOnOff - 1 2019-3-1 21:21:58 - debug: Setup reporting for 0x00178801026cd5d3 - genLevelCtrl - 1 2019-3-1 21:21:59 - debug: Successfully setup reporting for 0x00178801026cd5d3 - genOnOff - 1 2019-3-1 21:21:59 - debug: Successfully setup reporting for 0x00178801026cd5d3 - genLevelCtrl - 1 2019-3-1 21:56:49 - debug: Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'LWB010' (0x00178801026cd5d3) 2019-3-1 21:56:49 - info: MQTT publish: topic 'zigbee2mqtt/xBulb', payload '{"state":"OFF","brightness":50,"linkquality":28}' 2019-3-1 21:56:49 - debug: Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'LWB010' (0x00178801026cd5d3) 2019-3-1 21:56:49 - info: MQTT publish: topic 'zigbee2mqtt/xBulb', payload '{"state":"OFF","brightness":50,"linkquality":28}' 2019-3-1 21:56:56 - debug: Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'LWB010' (0x00178801026cd5d3) 2019-3-1 21:56:56 - info: MQTT publish: topic 'zigbee2mqtt/xBulb', payload '{"state":"ON","brightness":50,"linkquality":21}' 2019-3-1 21:56:56 - debug: Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'LWB010' (0x00178801026cd5d3) 2019-3-1 21:56:56 - info: MQTT publish: topic 'zigbee2mqtt/xBulb', payload '{"state":"ON","brightness":50,"linkquality":21}'

There are no logs if I change the brightness. The reported brightness of 50 seems to be a cached value and is not correct.

jbmbn commented 5 years ago

The reporting functionality is configured to only report on/off periodically. Other reports are generated only on change of the attribute.

One thing I think is still missing is retrieval of the current state of other attributes when a devices comes online (or zigbee2mqtt get restarted).

I've seen some articles that Philips Hue does not properly support the reporting function but I don't know what's true. If you want to try periodical reporting on the current level, you could try to change the value 3600 in deviceReport.js to 30 or so. Reports should be generated every 30 seconds. If that doesn't work, either the Philips Hue does not support reporting current level or it uses a different attribute that's not configured in deviceReport.js

JumpmanJunior commented 5 years ago

Indeed the problem seems to be caused by the Philips bulb. I have now tried the same with an Ikea bulb and the immediate reporting of brightness changes was working without problems.

I have also tested the mentioned periodical reporting. The Philips bulb sends no periodical reports at all. The Ikea bulb sends these as expected. So with the Philips bulb at the moment only immediate reporting of state changes (on/off) is working.

BudBundi commented 5 years ago

With the docker dev image from today and the latest dev firmware I get some strange warnings. I think its reporting related: zigbee2mqtt:warn 3/4/2019, 9:29:36 PM No converter available for 'GL-C-008' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-C-008","powerSource":1}}' zigbee2mqtt:warn 3/4/2019, 9:29:36 PM No converter available for 'GL-C-008' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-C-008","powerSource":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:07 PM No converter available for 'LED1537R6' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"manufacturerName":"IKEA of Sweden","modelId":"TRADFRI bulb GU10 WS 400lm","powerSource":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:07 PM No converter available for 'LED1537R6' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"zclVersion":1,"appVersion":17,"stackVersion":87,"hwVersion":1,"manufacturerName":"IKEA of Sweden"}}' zigbee2mqtt:warn 3/4/2019, 9:30:07 PM No converter available for 'LED1537R6' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"10":{"type":"Buffer","data":[network_key]},"modelId":"TRADFRI bulb GU10 WS 400lm","dateCode":"20170331","powerSource":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:07 PM No converter available for 'LED1537R6' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"10":[network_key]}}' zigbee2mqtt:warn 3/4/2019, 9:30:08 PM No converter available for 'LED1537R6' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"65533":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:08 PM No converter available for 'LED1537R6' with cid 'genIdentify', type 'attReport' and data '{"cid":"genIdentify","data":{"65533":1,"identifyTime":0}}' zigbee2mqtt:warn 3/4/2019, 9:30:08 PM No converter available for 'LED1537R6' with cid 'genGroups', type 'attReport' and data '{"cid":"genGroups","data":{"65533":1,"nameSupport":0}}' zigbee2mqtt:warn 3/4/2019, 9:30:09 PM No converter available for 'LED1537R6' with cid 'genScenes', type 'attReport' and data '{"cid":"genScenes","data":{"count":0,"currentScene":255,"currentGroup":0,"sceneValid":0,"nameSupport":0}}' zigbee2mqtt:warn 3/4/2019, 9:30:09 PM No converter available for 'LED1537R6' with cid 'genScenes', type 'attReport' and data '{"cid":"genScenes","data":{"65533":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:11 PM No converter available for 'LED1537R6' with cid 'haDiagnostic', type 'attReport' and data '{"cid":"haDiagnostic","data":{"numberOfResets":0,"macRxBcast":0,"macTxBcast":0,"aPSRxBcast":0,"aPSTxBcast":0}}' zigbee2mqtt:warn 3/4/2019, 9:30:12 PM No converter available for 'LED1537R6' with cid 'haDiagnostic', type 'attReport' and data '{"cid":"haDiagnostic","data":{"nwkFcFailure":0,"packetBufferAllocateFailures":0,"averageMacRetryPerApsMessageSent":0,"lastMessageLqi":132,"lastMessageRssi":-67}}' zigbee2mqtt:warn 3/4/2019, 9:30:12 PM No converter available for 'LED1537R6' with cid 'haDiagnostic', type 'devChange' and data '{"cid":"haDiagnostic","data":{"lastMessageLqi":132,"lastMessageRssi":-67}}' zigbee2mqtt:warn 3/4/2019, 9:30:12 PM No converter available for 'LED1537R6' with cid 'haDiagnostic', type 'attReport' and data '{"cid":"haDiagnostic","data":{"65533":1}}' zigbee2mqtt:warn 3/4/2019, 9:30:12 PM No converter available for 'LED1537R6' with cid 'lightLink', type 'attReport' and data '{"cid":"lightLink","data":{"65533":1}}'

With zigbee2mqtt:warn 3/4/2019, 9:29:36 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html. in between

alinelena commented 5 years ago

@BudBundi here the same but on a normal install... also plenty of errors too related to reporting, one needs to turn on/off the device to repair. repairing new devices is plugged by error node descriptor stuff. firmware keeps hitting errors are restart 60s to repair... thought this was fixed.

Koenkk commented 5 years ago

@BudBundi fixed in the latest dev branch.

milakov commented 5 years ago

I am getting this with the very latest dev both for GL-B-007Z and GL-B-008Z:

  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM No converter available for 'GL-B-007Z' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-007Z","powerSource":1}}'
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM No converter available for 'GL-B-007Z' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-007Z","powerSource":1}}'
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
alinelena commented 5 years ago

@milakov here the same just more of them. I do not know how is your network but mine with the latest dev and latest firmware from dev seems to be centred around the coordinator not the usual mesh. somehow I think the coordinator gets overwhelmed by requests to join. apparently i have 29 devices joined. also all the warning seem to be on powered devices... ikea lights or xiaomi socket.

milakov commented 5 years ago

@alinelena I have 24 devices and I am pretty sure they are connected via routers (5 of them).

Koenkk commented 5 years ago

I am getting this with the very latest dev both for GL-B-007Z and GL-B-008Z:

  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM No converter available for 'GL-B-007Z' with cid 'genBasic', type 'attReport' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-007Z","powerSource":1}}'
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM No converter available for 'GL-B-007Z' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-007Z","powerSource":1}}'
  zigbee2mqtt:warn 3/5/2019, 9:50:51 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.

Should be fixed in latest dev

milakov commented 5 years ago

@Koenkk Now I am seeing this:


  zigbee2mqtt:warn 3/8/2019, 11:19:33 AM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
  zigbee2mqtt:info 3/8/2019, 11:19:46 AM MQTT publish: topic 'zigbee2mqtt/0x00158d00024f2e59', payload '{"state":"OFF","power":0,"voltage":204,"consumption":103.39,"temperature":32,"linkquality":34,"last_seen":"2019-03-08T11:19:46+03:00"}'
  zigbee2mqtt:info 3/8/2019, 11:20:03 AM Device incoming...
  zigbee2mqtt:info 3/8/2019, 11:20:03 AM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
  zigbee2mqtt:warn 3/8/2019, 11:20:04 AM No converter available for 'GL-B-007Z' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-007Z","powerSource":1}}'
  zigbee2mqtt:warn 3/8/2019, 11:20:04 AM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
  zigbee2mqtt:info 3/8/2019, 11:20:32 AM MQTT publish: topic 'zigbee2mqtt/0x00158d0002561266/availability', payload 'online'
  zigbee2mqtt:info 3/8/2019, 11:20:33 AM MQTT publish: topic 'zigbee2mqtt/0x00124b001b505747/availability', payload 'online'
  zigbee2mqtt:info 3/8/2019, 11:20:34 AM Device incoming...
  zigbee2mqtt:info 3/8/2019, 11:20:34 AM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
  zigbee2mqtt:warn 3/8/2019, 11:20:35 AM No converter available for 'GL-B-008Z' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"GLEDOPTO","modelId":"GL-B-008Z","powerSource":1}}'
  zigbee2mqtt:warn 3/8/2019, 11:20:35 AM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
  zigbee2mqtt:info 3/8/2019, 11:20:46 AM MQTT publish: topic 'zigbee2mqtt/0x00158d00024f2e59/availability', payload 'online'```
Koenkk commented 5 years ago

@milakov thanks, will be ignored in the next version.

apeeters commented 5 years ago

After enabling reporting on firmware 20190223, latest hassio zigbee2mqtt-edge I get the following error a few seconds after start. It seems to kill the cc2531: I have to unplug & plug it to get it working again.

zigbee2mqtt:error 3/10/2019, 10:23:33 PM {"message":"request timeout","stack":"Error: request timeout\n at CcZnp.<anonymous> (/app/node_modules/cc-znp/lib/ccznp.js:261:22)\n at Object.onceWrapper (events.js:273:13)\n at CcZnp.emit (events.js:182:13)\n at Timeout.<anonymous> (/app/node_modules/cc-znp/lib/ccznp.js:240:18)\n at ontimeout (timers.js:436:11)\n at tryOnTimeout (timers.js:300:5)\n at listOnTimeout (timers.js:263:5)\n at Timer.processTimers (timers.js:223:10)"}

buffeh commented 5 years ago

apeeters - I am running the same firmware and same latest hassio zigbee2mqtt-edge and I seem to get the same error.

I enabled reporting, it appeared to work fine (briefly), then the stick stopped responding and restarts resulted in the above error. I actually had to reflash the stick with the latest firmware to get zigbee-shepherd to start working again, multiple restarts didn't help until I did this. I then was able to recreate the issue by enabling reporting again and for me this reliably "breaks the stick" requiring a reflash to get things up and running again.

Everything seems to work "ok" if I don't enable reporting, although even with latest firmware and edge version I still have stability issues if I turn off / on all my lights at once, often all my bulbs stop responding with "no route" errors when I do this, requiring me to stop zigbee2mqtt, unplug and replug the stick, and restart zigbee2mqtt to get it all working again.

My network is about 15 Ikea Tradfri bulbs and a bunch of Xiaomi wireless 1 button and 2 button switches.

Koenkk commented 5 years ago

@apeeters do you experience the same with the 20190109 firmware? https://github.com/Koenkk/Z-Stack-firmware/tree/9215ec3183b6febe4bac3ebb5240f4285c69e6f0/coordinator/CC2531/bin

apeeters commented 5 years ago

@Koenkk I'd rather not downgrade below 20190215 to avoid having to re-pair everything. I will downgrade to 20190218 and try again.

apeeters commented 5 years ago

@Koenkk It seems I completely killed it: I can hardly turn on/of 1 group before I get timeouts and have to unplug the device to resurrect it. After swapping in another cc2531, everything works fine again (20190218 on 1.2.1 on hassio).

apeeters commented 5 years ago

I spoke too soon: the new one also crashes after a while (a few minutes for 20190218 to 15 minutes for 20190223). I'll keep a close eye on it.

buffeh commented 5 years ago

@apeeters it sounds like you have the same issue as me, disabling reporting and reflashing the stick with latest firmware should get it up and running again, as I said before it seems enabling reporting for us with latest Edge and latest firmware kills the stick requiring a reflash!

Koenkk commented 5 years ago

@apeeters @buffeh please provide the complete log up-to the crash.

apeeters commented 5 years ago

FWIW, I also have failing pings to "ZNCZ02LM - Xiaomi Mi power plug ZigBee (Router)". I'll check what happens when I remove it.

apeeters commented 5 years ago

@Koenkk You can find the log here: https://hastebin.com/ovofupojev.apache At 10:03:32 PM I turned group 8 on via mqtt, this triggers a change color event, but that does not matter since it was already crashed.

apeeters commented 5 years ago

FWIW, I also have failing pings to "ZNCZ02LM - Xiaomi Mi power plug ZigBee (Router)". I'll check what happens when I remove it.

Does not have any impact.