CC2531 Coordinator paired itself - Unsupported device

[Underknowledge]

Quite a stange thing Happend.
The coordinator paird itself to the network (in my understanding)
and throws errors that it isnt supported.

zigbee2mqtt:debug 2019-1-4 16:47:28 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'undefined' (0x00124b0018ed38d1)
zigbee2mqtt:warn 2019-1-4 16:47:28 Device with modelID 'undefined' is not supported.
zigbee2mqtt:warn 2019-1-4 16:47:28 Please see: https://koenkk.github.io/zigbee2mqtt/how_tos/how_to_support_new_devices.html

zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":11,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b0018ed38d1","nwkAddr":0},
of cause I rather would not throw my coordinator out of the network.

my guess is that the Hue motion sensor ( 'SML001' (0x0017880102010384) )has something to do with it.

20 minutes of logs:
https://hastebin.com/uzarewavay.makefile
Map:

[Koenkk]

Does your hue motion sensor still produce occupancy messages?

[Underknowledge]

jep.
today better then other days

Jan 04 17:49:43 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:43 Received zigbee message of type 'devChange' with data '{"cid":"msOccupancySensing","data":{"occupancy":1}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:44 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:44 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":1}}' of device 'undefined' (0x00124b0018ed38d1)
Jan 04 17:49:44 hassbian npm[521]:   zigbee2mqtt:warn 2019-1-4 17:49:44 Device with modelID 'undefined' is not supported.
Jan 04 17:49:44 hassbian npm[521]:   zigbee2mqtt:warn 2019-1-4 17:49:44 Please see: https://koenkk.github.io/zigbee2mqtt/how_tos/how_to_support_new_devices.html
Jan 04 17:49:44 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:44 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":1}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:44 hassbian npm[521]:   zigbee2mqtt:info 2019-1-4 17:49:44 MQTT publish: topic 'zigbee2mqtt/hue_motionsensor', payload '{"illuminance":15913,"linkquality":70,"temperature":22.04,"battery":58,"occupancy":true}'
Jan 04 17:49:53 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:53 Received zigbee message of type 'attReport' with data '{"cid":"msIlluminanceMeasurement","data":{"measuredValue":15950}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:53 hassbian npm[521]:   zigbee2mqtt:info 2019-1-4 17:49:53 MQTT publish: topic 'zigbee2mqtt/hue_motionsensor', payload '{"illuminance":15950,"linkquality":70,"temperature":22.04,"battery":58,"occupancy":true}'
Jan 04 17:49:53 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:53 Received zigbee message of type 'devChange' with data '{"cid":"msIlluminanceMeasurement","data":{"measuredValue":15950}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:57 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:57 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:57 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:57 Received zigbee message of type 'devChange' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:57 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:57 Received zigbee message of type 'attReport' with data '{"cid":"msIlluminanceMeasurement","data":{"measuredValue":15962}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:57 hassbian npm[521]:   zigbee2mqtt:info 2019-1-4 17:49:57 MQTT publish: topic 'zigbee2mqtt/hue_motionsensor', payload '{"illuminance":15962,"linkquality":70,"temperature":22.04,"battery":58,"occupancy":true}'
Jan 04 17:49:57 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:57 Received zigbee message of type 'devChange' with data '{"cid":"msIlluminanceMeasurement","data":{"measuredValue":15962}}' of device 'SML001' (0x0017880102010384)
Jan 04 17:49:58 hassbian npm[521]:   zigbee2mqtt:debug 2019-1-4 17:49:58 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'undefined' (0x00124b0018ed38d1)

just occurd - wife moved past the sensor
https://hastebin.com/lufunazomi.coffeescript - would say 17:55:27 she should have triggerd the sensor
shortly afterwards me:
https://hastebin.com/kazameyugo.coffeescript

It meight be that most times its working for like 2 hours and then the coordinator takes over.

[ryanbeaton]

Seen here also so not just you.

#176 (comment)

Not sure what version and coordinator version does it

[highground88]

Re #176, I'm running the latest firmware (24-10-18) on the CC2531 coordinator.

Thanks @ryanbeaton for the tag. Glad it's not just me again...

Happens with only 1 other device in the network for me (Nue 2 gang switch), another device (Aqara door sensor) works fine whilst this continues to occur on the switch outputs.

[Underknowledge]

I did go for the alternative max devices - revision 20181119, so either both versions are suffering from this or its meight be a bug in Vesion 1.0.1 wich we have in common.
The hue movement sensor is kind of an *** permit_join: false isn't honored at all from this device - even after a factory reset it's repairing itsef.
@highground88 did you tryed to throw out the coordinator or the nue/aquara? If, What happend?

[simonvanderveldt]

I'm seeing the same behavior. Using 1.0.1 but I'm still on the 20180815 firmware for the CC2531 coordinator.

Note that I'm getting the exact same type of messages (attReport for msOccupancySensing). I'm also using the Hue motion sensors.

zigbee2mqtt:debug 2019-1-7 20:51:40 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'SML001' (0x<proper-device-id>)
zigbee2mqtt:debug 2019-1-7 20:51:42 Received zigbee message of type 'attReport' with data '{"cid":"msOccupancySensing","data":{"occupancy":0}}' of device 'undefined' (0x<coordinator-id>)

It seems to be/could be related to the so far for me unexplained 2s delayed repeat of the attReport msOccupancySensing message described here Koenkk/zigbee-herdsman-converters#184 (comment)

P.S. Initally I didn't notice it was the coordinator so I deleted it 😛 but it immediately joined the network after that:

zigbee2mqtt:info 2019-1-7 20:29:41 Successfully removed 0x<coordinator-id>
zigbee2mqtt:info 2019-1-7 20:29:41 MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_removed","message":"0x<coordinator-id>"}'
zigbee2mqtt:info 2019-1-7 20:31:41 New device with address 0x<coordinator-id> connected!
zigbee2mqtt:info 2019-1-7 20:31:41 MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":"0x<coordinator-id>"}'

[Koenkk]

The firmware isn't the problem. Could you try uncommenting https://github.com/Koenkk/zigbee2mqtt/blob/master/lib/zigbee.js#L87 till https://github.com/Koenkk/zigbee2mqtt/blob/master/lib/zigbee.js#L93 and check if this still happens?

[Kryzek]

I commented out those lines from line 87 to 93 as mentioned above and my warnings (#876) are not showing up anymore :)

[Underknowledge]

Nice, moving forward then.

[neerdoc]

I'm running this as the hassio-plugin (danielwelch/hassio-zigbee2mqtt). Where do I find this file? I tried searching the file system for it without luck.

[Koenkk]

Should be fixed in the dev branch

[neerdoc]

Tried the dev branch now. It did not help since the fix only seems to ignore messages from my device when they are identified to be from the coordinator. The device gets registered as the coordinator and subsequent messages are still ignored. Previously they where ignored because the id was unknown; now they are ignored because they are identified as being sent from the coordinator (which they are and were). But the root cause is still there; the device is registered with the address of the coordinator.

I have pasted some logs showing this: https://pastebin.com/zqYYV8vV

[Koenkk]

@neerdoc that right, but looking at your log, I see that also messages from the device are received, do you have any problem with the device itself?

[neerdoc]

Yes, I can't get it to work properly it seems. It is a smoke detector that is supposed to be supported (HS1SA - HEIMAN).

If I reset the device, remove it from the database and restart, I can connect it. Pushing the test button after connection seems to do nothing (identified as coordinator but maybe I misunderstand).

If I restart the zigbee2mqtt system it fails to reconnect. https://pastebin.com/WcpZWuvV

[Koenkk]

@neerdoc that probably fails because the device is sleeping, could you keep the device awake when starting zigbee2mqtt (e.g. by pressing the button on the motion sensor).

[neerdoc]

I have tried to debug this further by attaching the sniffer directly to my computer, so hassio-plugin is not the issue.

I added a shepherd-converter to get a more detailed output from what is happening, I have attached the log here: https://pastebin.com/2nbHij2M

The thing is, that if I restart zigbee2mqtt and press the test button on the smoke detector, the message gets through to the converter and I get the printout. But after the startup is finished, all the messages are intercepted as coming from the coordinator and discarded before ever reaching the converter.

I also found a problem with the converter that is already in the repo for this device. The msg data is deeper than in the code. I.e., const zoneStatus = msg.data.zoneStatus; should be const zoneStatus = msg.data.data.zoneStatus;

Any hints on where I can debug further to understand why the message gets through early in the startup phase but not later?

[Koenkk]

@neerdoc you are having the same issue as in #176.

I'm wondering what happens when you apply the solution from #801 (comment), you should be able to find the file under /app/lib/zigbee.js

[neerdoc]

Tested this and sure enough it seems to work now. I now get two messages for each push/release of the test button: "devChange" and "statusChange".

The "devChange" works out of the box, i.e., detects smoke on/off.
The "statusChange" does nothing, just reports the zoneId=23, i.e., same message both push and release. For "statusChange" I need the extra data (msg.data.data.zoneId). That is not required for the original "devChang" (works with msg.data.zoneStatus).

So what are the lines I just commented out supposed to do?

[ryanbeaton]

@neerdoc

So what are the lines I just commented out supposed to do?

/** * This is a fake cie app which makes it possible for some iAS devices to join the network. * Based on: https://github.com/zigbeer/zapp-cie */

Sad that is having unexpected consequences

[Koenkk]

@neerdoc does it stop working once you uncomment it?

[Kryzek]

I'm getting also these:

  zigbee2mqtt:debug 1/22/2019, 6:54:10 AM Received zigbee message of type 'statusChange' with data '{"cid":"ssIasZone","zoneStatus":33}' of device 'undefined' (0x00124b0014d9d7f3)
  zigbee2mqtt:debug 1/22/2019, 6:54:10 AM Ignoring message from coordinator
  zigbee2mqtt:debug 1/22/2019, 6:54:10 AM Received zigbee message of type 'statusChange' with data '{"cid":"ssIasZone","zoneStatus":33}' of device 'CSW_ADUROLIGHT' (0x00158d0001cca9aa)

0x00124b0014d9d7f3 being my coordinator

I'm using dev branch of zigbee2mqtt version 1.0.1 (commit #a43cd5a)

I had one CSW_ADUROLIGHT paired earlier and these messages did not appear then (atleast I didn't notice) but they started appearing after I paired another CSW_ADUROLIGHT sensor.

[Koenkk]

Perhaps a solution would be to only mount this when permit_join: true.

[neerdoc]

Put some more effort into debugging this.

1. Comment out the 8 lines and restart.
2. Join my two smoke devices.
3. I can now push the test button on any of the device and it works correctly.
4. Restarted. Still works.
5. Uncomment the 8 lines and restart. Still works.
6. Removed battery from one smoke device and reconnected it. Still works.
7. Unlink one smoke device and rejoin it.
8. The unlinked device does not work anymore!
9. The device I left connected still works.

So it seems that if the 8 lines are there during the join phase it breaks it. Once joined to the network it does not matter anymore. I will try to see if there is a difference in the logs between joining a device when the 8 lines are commented and not.

[neerdoc]

More info:
There are some minor differences in the database files, and I therefore tried changing lots of stuff in them to see if I could get it to work. In the end, I could determine that some information must be set in the device itself, because even copying a working database file to overwrite the database from the non-working join would not allow the device to start working again.

My best guess is the iasCieAddr variable gets stored in the device and is causing the problems because it was the only obvious difference:
"iasCieAddr":"0x0000000000000000" in the working case
"iasCieAddr":"0x00124b0018ed0e7d" in the non-working case (and that is the address of the coordinator).

[Kryzek]

Just throwing out an idea. Feels like the device itself reports the address that gets stored (iasCieAddr). What happens if you tell it to store it's own id?

[Koenkk]

@neerdoc can you try:

• Remove all changes you made
• Update to the latest dev branch
• Remove https://github.com/Koenkk/zigbee-shepherd-converters/blob/master/devices.js#L1985 to https://github.com/Koenkk/zigbee-shepherd-converters/blob/master/devices.js#L1993
• Re-pair devices and check if they work.

This will prevent the iasCieAddr from written to the device.

[neerdoc]

Tried that and no success. Removing those lines prevents the device from configuring it seems.

I also tried changing the 'iasCieAddr' address to the device, to 0x000000000000 and commenting out just that line. Still no luck. In those cases it cases it configures and sends a first "online" message, but nothing when I push the test button.

I did notice that regardless if the "8 lines" (the fake cie app) are commented or not, the device seems to register the coordinator on the "iasCieAddr". And it works in one case and not the other... So in both cases it seems to write the "iasCieAddr" to the device. The funny thing is the database, in one case it writes the "iasCieAddr" as the coordinator address and the other as zeros. But manually changing the database after the connection is done does not change anything either.

I'm totally stumped. Is something written to the sniffer that could be the problem?

[neerdoc]

Just to clarify:

If the fake cie app is on during join of device it always fails.
If the fake cie app is off during join of device it always works.
It does not matter if the fake cie app is on or off after the join.

[neerdoc]

Ok, I just started commenting out and changing code in the cie.js file and this is what I found:

If I change this line (12):
cieClusters.init('ssIasZone', 'dir', {value: 2}); // Client Side(Output)
to this:
cieClusters.init('ssIasZone', 'dir', {value: 1}); // Client Side(Output)
It works. Don't know why. Does anyone else?

[Koenkk]

@neerdoc I also don't know exactly what it does, but it has do something with the direction, does it also work with: cieClusters.init('ssIasZone', 'dir', {value: 3}); ?

[neerdoc]

Ok, tested some more. Value 0 or 1 works. Value 2 or 3 fails.

Found this on the internet. They set it to 0, but never tells why. I also tried reading the specification but I can't really find anything specific there either.

Can someone with a device (that requires the fake CIE App) other than the HS1SA try to set this to 0 to see that it still works for those devices too?

Oh, the specification seems to state that the "iasCieAddr" should be the address of the device and not the coordinator. Rather, the coordinator should actually check that the "iasCieAddr" is correct and ignore messages that have it wrong.

[Koenkk]

@neerdoc originally this has been added for #507, I will ask for help there.

[neerdoc]

Found a fix in the end that does not mess with the fake Cie App at all. Simply removing the iasCieAddr command from being sent to the device allows it to function properly.

Created a pull request in the shepherd-converters repo.

[Koenkk]

To all: are there any other issues left? can we close this issue?

[JLFN]

Yes HS1SA Still not wokring Starting zigbee2mqtt version 1.0.1 (commit #16f3e88
But i works when i download zigbee-shepherd-converters master from today. I thought that was included in zigbee2mqtt dev packaged.
https://hastebin.com/izetidecic.sql

[neerdoc]

@JLFN Did you repair your devices? Since the change is affecting what is written to the device during the pairing process, the device needs to be removed and rejoined again. From your supplied logfile it seems like you just started the new version.

[neerdoc]

@Koenkk I just tried this as well on my hassio-installation and it fails just as @JLFN said. Looked at the commits and the commit you refer to was made the day before my PR. Checking the version of the shepherd-converters library it shows 7.0.25, which is was also set before my PR. I don't know how npm calculates its dependencies, but it seems to me that you need to bump the version of shepherd-converters and then update the dependency here, correct?

[Koenkk]

@neerdoc you are right. I just updated zigbee2mqtt to the latest zigbee-shepherd-converters.

New docker image will be available in an hour.

[neerdoc]

Tested this in my Hassio-installation and it works for me and the HS1SA. Pushing the test button now register as "smoke=true" in Home Assistant interface.

[stale]

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.