permit_join false not honored #538

dlashua · 2018-10-25T14:25:45Z

Running Dev version...

When a device is removed (via MQTT), the device immediately pairs again and is allowed to do so despite permit_join being false. I've tested this through configuration file and by setting permit_join via MQTT.

The log shows "disabling joining new devices", so I know the message is being sent and received correctly. Then I remove the device and it immediately joins again. If I remove power from the device and then remove it from zigbee, of course, it doesn't re-pair. But, as soon as I put power to the device again, it pairs, despite permit_join still being false.

Device is a Model 74283 (Sylvania Lightify Dimmable Soft White A19 Bulb).

tb-killa · 2018-10-25T18:18:00Z

Hi this "strange" restrained construct return if the device themselve doesn´t remove sucessfully from the network.
technically we mark the device as removed from the database.db as forced process.
from what i see in fact .. most of manufacturer refer to the factory reset of the end-device to get them complete clean. don´t know if this is a result of strange zigbee specification but it helps.

dlashua · 2018-11-07T10:31:38Z

So, to rephrase what you're saying, the "correct" way to remove a device is to first reset the device and THEN perform the remove function?

Underknowledge · 2018-11-19T20:01:03Z

I`m just here with a Hue motion sensor
permit_join is set to false

Even when first reset:

 MQTT publish, topic: 'zigbee2mqtt/bridge/log', payload: '{"type":"device_removed","message":"0x0017880102010384"}'
 20:49:44 New device with address 0x0017880102010384 connected!
zigbee2mqtt:info 2018-11-19 20:49:44 MQTT publish, topic: 'zigbee2mqtt/bridge/log', payload: '{"type":"device_connected","message":"0x0017880102010384"}'

Some devices are very.. Presistant
https://pastebin.com/NfT4Ev09

stale · 2019-01-18T23:15:14Z

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.

Fabiancrg · 2019-03-11T19:18:06Z

Hi,

I had the same problem with Aqara LED bulbs (routers).
Each time I removed the device using MQTT zigbee2mqtt/bridge/config/remove topic, it was back a few seconds later, even with permit join set to false.
What I had to do is the following:
1- Remove power from LED bulb
2- Remove device using zigbee2mqtt/bridge/config/remove
3- Stop zigbee2mqtt
4- Reset the LED bulb
5- Restart zigbee2mqtt
After that, it was not possible to add the bulb back without permit join set to true

Done on Zigbee2mqtt 1.2.1 + CC2531 coordinator with firmware version 20190223

uncle-fed · 2019-03-23T18:46:02Z

I would like to re-open this. I've experienced similar issues as described above.

Today I was playing with a Xiaomi temperature sensor and a Gledopto LED controller.
Both were joining (and then re-joining) even when permit_join was set to false and even if I did all the steps as suggested by @Fabiancrg above.

Moreover, one of the devices (Xiaomi sensor) has never been paired with my zigbee2mqtt setup before (it is a brand new sensor) and the very first time I tried to pair it the config option permit_join was set to false (the log file also showed this: "PM Zigbee: disabling joining new devices." during zigbee2mqtt startup.

So in my case, the permit_join setting is definitely not honored (using dev branch, updated today).

'zigbee2mqtt/bridge/config', payload '{"version":"1.2.1","commit":"1ea694c","coordinator_firmware":20190223,"log_level":"info","permit_join":false}'

uncle-fed · 2019-03-30T14:26:39Z

Please let me know if I can help and troubleshoot / debug this in any way.

It is really annoying for me now since I am running Philips Hue bridge as well as zigbee2mqtt at the same time and it is impossible for me to pair any of my (brand new) Hue devices with the Hue bridge.

zigbee2mqtt almost instantly "intercepts" all fresh devices before I am able to detect them with Hue bridge. I have to shutdown my Raspberry Pi every time I need to pair a device with the Hue bridge, even though the permit_join is set to false.

Koenkk · 2019-03-30T14:30:01Z

@uncle-fed I expect this should be improved with the latest dev branch, be sure that the device you don't want to join isn't in the database.db.

uncle-fed · 2019-03-30T15:35:57Z

I'm afraid there is no improvement on my side. Just pulled the latest updates in the dev branch and here is what I get:

$ cd /opt/zigbee2mqtt/data
$ grep 0x7cb03eaa00a3c718 database.db # produces nothing
$ grep 0x7cb03eaa00a3c718 configuration.yaml # produces nothing

now (re)starting zigbee2mqtt with log_level: debug and permit_join: false:

Mar 30 16:23:46 openHABianPi systemd[1]: Stopped zigbee2mqtt.
Mar 30 16:23:46 openHABianPi systemd[1]: Started zigbee2mqtt.
Mar 30 16:23:49 openHABianPi npm[17658]: > [email protected] start /opt/zigbee2mqtt
Mar 30 16:23:49 openHABianPi npm[17658]: > node index.js
Mar 30 16:23:51 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:51 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-03-30.16-23-51'
Mar 30 16:23:51 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:51 PM Removing old log directory '/opt/zigbee2mqtt/data/log/2019-03-23.19-20-28'
Mar 30 16:23:52 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:52 PM Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[25],"precfgkey":"HIDDEN"},"dbPath":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
Mar 30 16:23:52 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:52 PM Loaded state from file /opt/zigbee2mqtt/data/state.json
Mar 30 16:23:52 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:52 PM Saving state to file /opt/zigbee2mqtt/data/state.json
Mar 30 16:23:52 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:52 PM Starting zigbee2mqtt version 1.2.1 (commit #91bc56a)
Mar 30 16:23:52 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:52 PM Starting zigbee-shepherd
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM zigbee-shepherd started
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM Coordinator firmware version: '20190223'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:55 PM zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":25,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b0018e1a73a","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190223},"startTime":1553959435,"joinTimeLeft":0}
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM Currently 10 devices are joined:
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraSwitchWired (0x00158d0002a718ff): QBKG03LM - Xiaomi Aqara double key wired wall switch (Router)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraDoorSensor (0x00158d000272ed0d): MCCGQ11LM - Xiaomi Aqara door & window contact sensor (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MijiaDoorSensor (0x00158d0002b7b1ed): MCCGQ01LM - Xiaomi MiJia door & window contact sensor (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM HueBulb (0x0017880102ca5bc8): 9290012573A - Philips Hue white and color ambiance E26/E27/E14 (Router)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraOccupancy (0x00158d0002c7174b): RTCGQ11LM - Xiaomi Aqara human body movement and illuminance sensor (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraCube (0x00158d00027de5f4): MFKZQ01LM - Xiaomi Mi/Aqara smart home cube (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraPlug (0x00158d00024d8d32): ZNCZ02LM - Xiaomi Mi power plug ZigBee (Router)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraTemperature (0x00158d0002720d78): WSDCGQ11LM - Xiaomi Aqara temperature, humidity and pressure sensor (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraSwitch2Btn (0x00158d0002b4b01e): WXKG02LM - Xiaomi Aqara double key wireless wall switch (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM AqaraSwitch1Btn (0x00158d00028f5bd4): WXKG03LM - Xiaomi Aqara single key wireless wall switch (EndDevice)
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM Zigbee: disabling joining new devices.
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM Connecting to MQTT server at mqtt://localhost
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM zigbee-shepherd ready
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM Connected to MQTT server
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitchWired', payload '{"state_right":"OFF","linkquality":94,"state_left":"OFF"}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraDoorSensor', payload '{"contact":true,"linkquality":99,"battery":100,"voltage":3025}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/MijiaDoorSensor', payload '{"contact":true,"linkquality":89,"battery":97,"voltage":2995}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/HueBulb', payload '{"state":"OFF","linkquality":89,"brightness":96,"color":{"x":0.457,"y":0.41,"saturation":55.1,"hue":46.2},"color_temp":366,"color_mode":2}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraOccupancy', payload '{"illuminance":39,"linkquality":92,"occupancy":false,"battery":100,"voltage":3015}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraCube', payload '{"battery":100,"voltage":3005,"linkquality":86}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraPlug', payload '{"state":"OFF","power":0,"voltage":null,"consumption":0,"temperature":29,"linkquality":49}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraTemperature', payload '{"humidity":34.2,"linkquality":89,"temperature":27.86,"pressure":1005,"battery":100,"voltage":3015}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitch2Btn', payload '{"battery":100,"voltage":3045,"linkquality":86}'
Mar 30 16:23:55 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:55 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitch1Btn', payload '{"battery":100,"voltage":3025,"linkquality":89}'
Mar 30 16:23:56 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:23:56 PM MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.2.1","commit":"91bc56a","coordinator_firmware":20190223,"log_level":"debug","permit_join":false}'
Mar 30 16:23:56 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:23:56 PM Mounted the cieApp (epId 11)

Now plugging in new Zigbee device (Osram Smart+ Wall Plug) and resetting it so it goes into pairing mode:

Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"hwVersion":1,"manufacturerName":"OSRAM","modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"swBuildId":"V1.04.12"}}' of device 'undefined' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:29 PM New device 'undefined' with address 0x7cb03eaa00a3c718 connected!
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Saving state to file /opt/zigbee2mqtt/data/state.json
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:29 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":"0x7cb03eaa00a3c718","meta":{}}'
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:warn 3/30/2019, 4:26:29 PM Device with modelID 'undefined' is not supported.
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:warn 3/30/2019, 4:26:29 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:29 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"ON","linkquality":81}'
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Configuring 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718) ...
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":1,"appVersion":12,"stackVersion":2,"hwVersion":1,"manufacturerName":"OSRAM"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"deviceEnabled":1,"swBuildId":"V1.04.12"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:29 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:29 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'readRsp' with data '{"cid":"genIdentify","data":{"identifyTime":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'readRsp' with data '{"cid":"genGroups","data":{"nameSupport":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:30 PM Successfully configured 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718)
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'readRsp' with data '{"cid":"genScenes","data":{"count":0,"currentScene":0,"currentGroup":0,"sceneValid":0,"nameSupport":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:30 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:30 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'readRsp' with data '{"cid":"genOnOff","data":{"onOff":1,"globalSceneCtrl":1,"onTime":0,"offWaitTime":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:31 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"ON","linkquality":81}'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'readRsp' with data '{"cid":"haElectricalMeasurement","data":{"measurementType":8,"activePower":400}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'readRsp' with data '{"cid":"manuSpecificOsram","data":{"0":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devIncoming' with data '"0x7cb03eaa00a3c718"' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:31 PM Device incoming...
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:31 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'devStatus' with data '"online"' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:31 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 16:26:31 openHABianPi npm[17658]:   zigbee2mqtt:info 3/30/2019, 4:26:31 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"ON","linkquality":81}'
Mar 30 16:26:40 openHABianPi npm[17658]:   zigbee2mqtt:debug 3/30/2019, 4:26:40 PM Received zigbee message of type 'endDeviceAnnce' with data '"0x7cb03eaa00a3c718"' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3

Now repeating the commands above:

$ grep 0x7cb03eaa00a3c718 configuration.yaml
  '0x7cb03eaa00a3c718':
    friendly_name: '0x7cb03eaa00a3c718'

$ grep 0x7cb03eaa00a3c718 database.db
{"id":12,"type":"Router","ieeeAddr":"0x7cb03eaa00a3c718","nwkAddr":10932,"manufId":48042,"epList":[3],"status":"online","joinTime":1553959589,"endpoints":{"3":{"profId":49246,"epId":3,"devId":16,"inClusterList":[0,3,4,5,6,2820,4096,64527],"outClusterList":[25],"clusters":{}}},"_id":"zDnUITf819hcBQAA"}
{"id":12,"type":"Router","ieeeAddr":"0x7cb03eaa00a3c718","nwkAddr":10932,"manufId":48042,"manufName":"OSRAM","powerSource":"Mains (single phase)","modelId":"Plug 01","epList":[3],"hwVersion":1,"swBuildId":"V1.04.12","status":"online","joinTime":1553959589,"endpoints":{"3":{"profId":49246,"epId":3,"devId":16,"inClusterList":[0,3,4,5,6,2820,4096,64527],"outClusterList":[25],"clusters":{}}},"dateCode":"20140331DEOS****","_id":"zDnUITf819hcBQAA"}
{"id":12,"type":"Router","ieeeAddr":"0x7cb03eaa00a3c718","nwkAddr":10932,"manufId":48042,"manufName":"OSRAM","powerSource":"Mains (single phase)","modelId":"Plug 01","epList":[3],"hwVersion":1,"swBuildId":"V1.04.12","status":"online","joinTime":1553959589,"endpoints":{"3":{"profId":49246,"epId":3,"devId":16,"inClusterList":[0,3,4,5,6,2820,4096,64527],"outClusterList":[25],"clusters":{"genBasic":{"dir":{"value":1},"attrs":{"zclVersion":1,"appVersion":12,"stackVersion":2,"hwVersion":1,"manufacturerName":"OSRAM","modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"deviceEnabled":1,"swBuildId":"V1.04.12"}},"genIdentify":{"dir":{"value":1},"attrs":{"identifyTime":0}},"genGroups":{"dir":{"value":1},"attrs":{"nameSupport":0}},"genScenes":{"dir":{"value":1},"attrs":{"count":0,"currentScene":0,"currentGroup":0,"sceneValid":0,"nameSupport":0}},"genOnOff":{"dir":{"value":1},"attrs":{"onOff":1,"globalSceneCtrl":1,"onTime":0,"offWaitTime":0}},"genOta":{"dir":{"value":2},"attrs":{}},"haElectricalMeasurement":{"dir":{"value":1},"attrs":{"measurementType":8,"activePower":400}},"lightLink":{"dir":{"value":1},"attrs":{}},"manuSpecificOsram":{"dir":{"value":1},"attrs":{"0":0}}}}},"dateCode":"20140331DEOS****","_id":"zDnUITf819hcBQAA"}

So basically, same as before, the device joins immediately, even though it was never present neither in configuration.yaml nor in the database.db.

Koenkk · 2019-03-30T15:49:36Z

@uncle-fed I've added some extra logging, can you up to the latest dev branch and make sure that 0x7cb03eaa00a3c718 is not in database.db.

uncle-fed · 2019-03-30T16:11:28Z

I repeated the test above exactly same way (making sure that 0x7cb03eaa00a3c718 was not in the /opt/zigbee2mqtt/data/database.db). I saw the following message that you added to the debug output:

 Allowing device '0x7cb03eaa00a3c718' to join (already connected device)

Hmm...

uncle-fed · 2019-03-30T16:13:47Z

There must be some flaw in the logic that handles the 'incoming device' messages.

zigbee2mqtt:info 3/30/2019, 5:09:26 PM New device 'undefined' with address 0x7cb03eaa00a3c718 connected!

this message is much earlier than the

zigbee2mqtt:debug 3/30/2019, 5:09:34 PM Allowing device '0x7cb03eaa00a3c718' to join (already connected device)

So it seems that the check is done too late ??

Koenkk · 2019-03-30T16:39:11Z

@uncle-fed this is expected, can you try to ban the device: http://www.zigbee2mqtt.io/information/mqtt_topics_and_message_structure.html#zigbee2mqttbridgeconfigban

uncle-fed · 2019-03-30T18:37:44Z

executed the following:

mosquitto_pub -t 'zigbee2mqtt/bridge/config/ban' -m 0x7cb03eaa00a3c718

this got added to configuration.yaml:

ban:
  - '0x7cb03eaa00a3c718'

restarted zigbee2mqtt and the checked that database.db did not contain any references to 0x7cb03eaa00a3c718.

additionally completely powercycled Raspberry Pi and reset the Osram plug while Raspberry Pi was down.

Here is the debug log when turning on Osram plug and entering pairing mode.
The pairing is still performed and now I got two entries in the configuration.yaml: one in the ban section and another one in the devices section:

devices:
  ...
  '0x7cb03eaa00a3c718':
    friendly_name: '0x7cb03eaa00a3c718'
    retain: false
ban:
  - '0x7cb03eaa00a3c718'

Mar 30 19:34:12 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:12 PM Starting zigbee2mqtt version 1.2.1 (commit #2f52b85)
Mar 30 19:34:12 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:12 PM Starting zigbee-shepherd
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM zigbee-shepherd started
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM Coordinator firmware version: '20190223'
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:14 PM zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":25,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b0018e1a73a","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190223},"startTime":1553970854,"joinTimeLeft":0}
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM Currently 10 devices are joined:
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraSwitchWired (0x00158d0002a718ff): QBKG03LM - Xiaomi Aqara double key wired wall switch (Router)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraDoorSensor (0x00158d000272ed0d): MCCGQ11LM - Xiaomi Aqara door & window contact sensor (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM MijiaDoorSensor (0x00158d0002b7b1ed): MCCGQ01LM - Xiaomi MiJia door & window contact sensor (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM HueBulb (0x0017880102ca5bc8): 9290012573A - Philips Hue white and color ambiance E26/E27/E14 (Router)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraOccupancy (0x00158d0002c7174b): RTCGQ11LM - Xiaomi Aqara human body movement and illuminance sensor (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraCube (0x00158d00027de5f4): MFKZQ01LM - Xiaomi Mi/Aqara smart home cube (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraPlug (0x00158d00024d8d32): ZNCZ02LM - Xiaomi Mi power plug ZigBee (Router)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraTemperature (0x00158d0002720d78): WSDCGQ11LM - Xiaomi Aqara temperature, humidity and pressure sensor (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraSwitch2Btn (0x00158d0002b4b01e): WXKG02LM - Xiaomi Aqara double key wireless wall switch (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM AqaraSwitch1Btn (0x00158d00028f5bd4): WXKG03LM - Xiaomi Aqara single key wireless wall switch (EndDevice)
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM Zigbee: disabling joining new devices.
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM Connecting to MQTT server at mqtt://localhost
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM zigbee-shepherd ready
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM Connected to MQTT server
Mar 30 19:34:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:14 PM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitchWired', payload '{"state_right":"OFF","linkquality":94,"state_left":"OFF"}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraDoorSensor', payload '{"contact":true,"linkquality":89,"battery":100,"voltage":3025}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/MijiaDoorSensor', payload '{"contact":true,"linkquality":89,"battery":97,"voltage":2995}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/HueBulb', payload '{"state":"OFF","linkquality":89,"brightness":96,"color":{"x":0.457,"y":0.41,"saturation":55.1,"hue":46.2},"color_temp":366,"color_mode":2}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraOccupancy', payload '{"illuminance":589,"linkquality":81,"occupancy":false,"battery":100,"voltage":3015}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraCube', payload '{"battery":100,"voltage":3005,"linkquality":89}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraPlug', payload '{"state":"OFF","power":0,"voltage":null,"consumption":0,"temperature":29,"linkquality":89}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraTemperature', payload '{"humidity":34.08,"linkquality":86,"temperature":27.66,"pressure":1004.9,"battery":100,"voltage":3015}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitch2Btn', payload '{"battery":100,"voltage":3045,"linkquality":78}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/AqaraSwitch1Btn', payload '{"battery":100,"voltage":3025,"linkquality":89}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:15 PM MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.2.1","commit":"2f52b85","coordinator_firmware":20190223,"log_level":"debug","permit_join":false}'
Mar 30 19:34:15 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:15 PM Mounted the cieApp (epId 11)

Mar 30 19:34:45 openHABianPi npm[1263]:   zigbee2mqtt:error 3/30/2019, 7:34:45 PM Cannot get the Node Descriptor of the Device: 0x7cb03eaa00a3c718 (Error: Timed out after 10000 ms)
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:57 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"hwVersion":1,"manufacturerName":"OSRAM","modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"swBuildId":"V1.04.12"}}' of device 'undefined' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:57 PM New device 'undefined' with address 0x7cb03eaa00a3c718 connected!
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:57 PM Saving state to file /opt/zigbee2mqtt/data/state.json
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:34:57 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":"0x7cb03eaa00a3c718","meta":{}}'
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:warn 3/30/2019, 7:34:57 PM Device with modelID 'undefined' is not supported.
Mar 30 19:34:57 openHABianPi npm[1263]:   zigbee2mqtt:warn 3/30/2019, 7:34:57 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html
Mar 30 19:34:58 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:58 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":1,"appVersion":12,"stackVersion":2,"hwVersion":1,"manufacturerName":"OSRAM"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:34:58 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:58 PM Configuring 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718) ...
Mar 30 19:34:58 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:58 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"deviceEnabled":1,"swBuildId":"V1.04.12"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:34:58 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:58 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:34:59 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:59 PM Received zigbee message of type 'readRsp' with data '{"cid":"genIdentify","data":{"identifyTime":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:34:59 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:59 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:34:59 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:59 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:34:59 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:34:59 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:00 openHABianPi npm[1263]:   zigbee2mqtt:warn 3/30/2019, 7:35:00 PM Failed to configure 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718) ('Error: AF data request fails, status code: 205. No network route. Please confirm that the device has (re)joined the network.') (attempt #1)
Mar 30 19:35:00 openHABianPi npm[1263]:   zigbee2mqtt:warn 3/30/2019, 7:35:00 PM This can be ignored if the device is working properly
Mar 30 19:35:00 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:00 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:01 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:01 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:01 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:01 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:02 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:02 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Accept device incoming with ieeeAddr '0x7cb03eaa00a3c718' permit join is 'false'
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Allowing device '0x7cb03eaa00a3c718' to join (already connected device)
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Received zigbee message of type 'devIncoming' with data '"0x7cb03eaa00a3c718"' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:35:03 PM Device incoming...
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:35:03 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Configuring 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718) ...
Mar 30 19:35:03 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:03 PM Received zigbee message of type 'devStatus' with data '"online"' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:35:14 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:35:14 PM Successfully configured 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718)
Mar 30 19:35:14 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:14 PM Ping 0x00158d0002a718ff (basic)
Mar 30 19:35:15 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:15 PM Ping 0x00158d00024d8d32 (basic)
Mar 30 19:35:15 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:15 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":1}}' of device 'lumi.plug' (0x00158d00024d8d32) of endpoint 1
Mar 30 19:35:15 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:15 PM Successfully pinged 0x00158d00024d8d32
Mar 30 19:35:16 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:16 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:35:16 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:35:16 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"ON","linkquality":97}'
Mar 30 19:35:16 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:16 PM Received zigbee message of type 'devChange' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Mar 30 19:35:27 openHABianPi npm[1263]:   zigbee2mqtt:debug 3/30/2019, 7:35:27 PM Received zigbee message of type 'attReport' with data '{"cid":"genBasic","data":{"65281":{"3":29,"5":9,"7":"0x0000000000000000","8":4894,"9":3081,"100":0,"149":0,"152":0,"154":16}}}' of device 'lumi.plug' (0x00158d00024d8d32) of endpoint 1
Mar 30 19:35:27 openHABianPi npm[1263]:   zigbee2mqtt:info 3/30/2019, 7:35:27 PM MQTT publish: topic 'zigbee2mqtt/AqaraPlug', payload '{"state":"OFF","power":0,"voltage":null,"consumption":0,"temperature":29,"linkquality":78}'
Mar 30 19:35:33 openHABianPi npm[1263]:   zigbee2mqtt:error 3/30/2019, 7:35:33 PM Failed to ping 0x00158d0002a718ff

Koenkk · 2019-04-01T18:30:35Z

Can you check again with the latest dev branch?

uncle-fed · 2019-04-06T11:42:21Z

I went and started completely from scratch with 0 byte database.db file and only the following contents of the configuration.yaml:

homeassistant: false
permit_join: false
mqtt:
  base_topic: zigbee2mqtt
  server: 'mqtt://localhost'
serial:
  port: /dev/ttyACM0
advanced:
  channel: 25
  log_level: debug
devices: {}
ban:
  - '0x7cb03eaa00a3c718'

Started zigbee2mqtt and saw this in the log:

Apr 06 13:27:07 openHABianPi systemd[1]: Started zigbee2mqtt.
Apr 06 13:27:10 openHABianPi npm[11729]: > [email protected] start /opt/zigbee2mqtt
Apr 06 13:27:10 openHABianPi npm[11729]: > node index.js
Apr 06 13:27:12 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:12 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-04-06.13-27-12'
Apr 06 13:27:12 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:12 PM Removing old log directory '/opt/zigbee2mqtt/data/log/2019-04-06.13-13-56'
Apr 06 13:27:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:13 PM Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[25],"precfgkey":"HIDDEN"},"dbPath":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
Apr 06 13:27:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:13 PM Loaded state from file /opt/zigbee2mqtt/data/state.json
Apr 06 13:27:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:13 PM Saving state to file /opt/zigbee2mqtt/data/state.json
Apr 06 13:27:13 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:13 PM Starting zigbee2mqtt version 1.2.1 (commit #32db1fd)
Apr 06 13:27:13 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:13 PM Starting zigbee-shepherd
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:15 PM zigbee-shepherd started
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:15 PM Coordinator firmware version: '20190223'
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:15 PM zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":25,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b0018e1a73a","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190223},"startTime":1554550035,"joinTimeLeft":0}
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:15 PM Currently 0 devices are joined:
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:15 PM Zigbee: disabling joining new devices.
Apr 06 13:27:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:15 PM Connecting to MQTT server at mqtt://localhost
Apr 06 13:27:16 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:16 PM zigbee-shepherd ready
Apr 06 13:27:16 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:16 PM Connected to MQTT server
Apr 06 13:27:16 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:16 PM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
Apr 06 13:27:16 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:27:16 PM MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.2.1","commit":"32db1fd","coordinator_firmware":20190223,"log_level":"debug","permit_join":false}'
Apr 06 13:27:16 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:27:16 PM Mounted the cieApp (epId 11)

At this time, the configuration.yaml file was unchanged and database.db got 2 records created, both with the type: coordinator and with the same _id hash (hope that this is the way it is supposed to be on a fresh system).

Then I turned on the Osram Smart+ Plug and put it into pairing mode.

Here is what the log file showed immediately:

Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"hwVersion":1,"manufacturerName":"OSRAM","modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"swBuildId":"V1.04.12"}}' of device 'undefined' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:06 PM New device 'undefined' with address 0x7cb03eaa00a3c718 connected!
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Saving state to file /opt/zigbee2mqtt/data/state.json
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:06 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"device_connected","message":"0x7cb03eaa00a3c718","meta":{}}'
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:warn 4/6/2019, 1:28:06 PM Device with modelID 'undefined' is not supported.
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:warn 4/6/2019, 1:28:06 PM Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":1,"appVersion":12,"stackVersion":2,"hwVersion":1,"manufacturerName":"OSRAM"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Configuring 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718) ...
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"modelId":"Plug 01","dateCode":"20140331DEOS****","powerSource":1,"deviceEnabled":1,"swBuildId":"V1.04.12"}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:06 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:06 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:07 PM Received zigbee message of type 'readRsp' with data '{"cid":"genIdentify","data":{"identifyTime":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:07 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:07 PM Received zigbee message of type 'readRsp' with data '{"cid":"genGroups","data":{"nameSupport":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:07 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:07 PM Successfully configured 0x7cb03eaa00a3c718 (0x7cb03eaa00a3c718)
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:07 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":1}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:07 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:07 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"ON","linkquality":99}'
Apr 06 13:28:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:13 PM Received zigbee message of type 'attReport' with data '{"cid":"genOnOff","data":{"onOff":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:13 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:13 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"OFF","linkquality":97}'
Apr 06 13:28:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:13 PM Received zigbee message of type 'readRsp' with data '{"cid":"genScenes","data":{"count":0,"currentScene":0,"currentGroup":0,"sceneValid":0,"nameSupport":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:13 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:13 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'readRsp' with data '{"cid":"genOnOff","data":{"onOff":0,"globalSceneCtrl":1,"onTime":0,"offWaitTime":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:14 PM MQTT publish: topic 'zigbee2mqtt/0x7cb03eaa00a3c718', payload '{"state":"OFF","linkquality":99}'
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'readRsp' with data '{"cid":"haElectricalMeasurement","data":{"measurementType":8,"activePower":28000}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:14 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:14 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:15 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:15 PM Received zigbee message of type 'readRsp' with data '{"cid":"manuSpecificOsram","data":{"0":0}}' of device 'Plug 01' (0x7cb03eaa00a3c718) of endpoint 3
Apr 06 13:28:15 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:15 PM Received zigbee message of type 'devInterview' with data '"0x7cb03eaa00a3c718"'
Apr 06 13:28:15 openHABianPi npm[11729]:   zigbee2mqtt:debug 4/6/2019, 1:28:15 PM Accept device incoming with ieeeAddr '0x7cb03eaa00a3c718' permit join is 'false'
Apr 06 13:28:15 openHABianPi npm[11729]:   zigbee2mqtt:info 4/6/2019, 1:28:15 PM Banned device tried to connect (0x7cb03eaa00a3c718)

After that, the contents of the configuration.yaml became the following:

homeassistant: false
permit_join: false
mqtt:
  base_topic: zigbee2mqtt
  server: 'mqtt://localhost'
serial:
  port: /dev/ttyACM0
advanced:
  channel: 25
  log_level: debug
devices:
  '0x7cb03eaa00a3c718':
    friendly_name: '0x7cb03eaa00a3c718'
    retain: false
ban:
  - '0x7cb03eaa00a3c718'

The database.db got 2 records added to it for the device with the same _id and type: Router.

So, it looked like the device was STILL added to both configuration.yaml as well as the database.db even with the permit_join and ban both disallowing it.

What is worse, the process did not stop at this point because the latest changes modified some logic. Now, the device is not really joined the Zigbee network (at least at some level) and retries every 15 seconds to do this. The log file grows with exactly same block of messages as above and the database.db keeps growing by 2 records every time into infinity, as if new devices was added again and again (the _id is different every time).

Koenkk · 2019-04-19T19:10:58Z

@uncle-fed this may actually be fixed by Z-Stack 3, please see #1445

uncle-fed · 2019-04-19T19:37:00Z

Thank you for the info. I was hoping that this rather fundamental broken feature could be fixed in a stable firmware. I am enthusiastic about this project in general but at this stage I was hoping to build something simple and stable that just works without resorting to flashing experimental firmware. I hope that the fixes can be backported to the current stable firmware. After all, if you have to run more than 1 zigbee network, the issue becomes significant. Im not sure how this should work if you have neighbors in a building who also have a smart home system that is Zigbee based. It would be a total nightmare.

Koenkk · 2019-04-19T20:38:12Z

If that firmware indeed fixes it, don't expect that changes can be backported. The firmware is not under my control and is maintained by Texas Instruments. Zigbee 3.0 has much better security policies compared to Zigbee 1.2 HA.

uncle-fed · 2019-04-20T07:24:40Z

How certain is it that the issue is in the firmware? Until now it looked like it was the nodejs code. Last experiment in the dev branch really changed the behavior although did not fix the issue.

Koenkk · 2019-04-22T10:56:39Z

The firmware is responsible for letting devices join, which means that non of this logic should be in the nodejs code. Everything added there is basically a hacky workaround.

uncle-fed · 2019-04-22T11:17:44Z

I just cannot believe I am the only person suffering from this and/or having major concern about this behaviour.

Permanently letting alien devices joining in would not only make it annoying when you are running more than 1 zigbee network yourself but would be completely nasty towards neighbours who would wonder why they cannot pair their newly bought smart lights with their bridge. Let alone security concerns of having random alien devices on your private network and having no control over it.

As much as I love the idea of getting rid of all proprietary bridges and Chinese clouds it would then remain just a proof of concept until this fundamental feature is functioning correctly. So much work already went into supporting so many devices and what a nasty surprise suddenly. :-(

So the NodeJS code sets some kind of flag in firmware? Can the firmware code be debugged somehow?

Koenkk · 2019-04-22T11:58:47Z

I'm not sure if I understand you correctly, I thought it only happened with devices that you already had paired to your network.

This of course doesn't (or shouldn't) happen with a factory fresh device which has never been in your network before. Is this the case?

uncle-fed · 2019-04-22T12:03:25Z

Please see my very first comment above: #538 (comment)

Yes, it happened and continues to happen with brand new devies, freshly unpacked from the store, never paired before

I would like to undestand something. Besides the configuration.yaml and database.db, does something somewhere (like firmware on a CC stick) keep another list of "known devices" that seems to be not controlled correctly via NodeJS code?

Koenkk · 2019-04-22T12:10:11Z

The coordinator does not keep a list of connected devices, in fact, this responsibility lies in the devices (they know the network key/channel).

I have the suspicion that some other device in your network allows joining of new devices (which does not honor permit_join: false). Could you provide the sniffing log when starting zigbee2mqtt and pairing a factory fresh device? (http://www.zigbee2mqtt.io/how_tos/how_to_sniff_zigbee_traffic.html).

uncle-fed · 2019-04-22T12:19:56Z

Okay, I will do the following very soon (not today):
I will turn off all Zigbee devices, remove them from this Zigbee network that is maintained by CC2531 stick (configuration.yaml, database.db) and then start with a single new Xiaomi wall switch, which is currently still sealed in its box. I have 2nd CC2531 stick which I can flash with the sniffing firmware.
I'll report afterwards.

Koenkk · 2019-04-22T12:32:51Z

@uncle-fed great! that sounds like a good test setup.

uncle-fed · 2019-04-27T22:30:12Z

I have successfully created new environment with Zigbee traffic sniffer in place and clean configuration.

So far I cannot reproduce the issue any more with one brand new device (never paired before) and one older device that I reset.

I am a bit at loss as to what was different before and will keep an eye on it when I start adding more devices. If I am able to reproduce it I'll report back again. Just as you suggested I also suspect some router-type device allowing unathorized joins but so far I am unable to figure out what device it is.

For now we can close this issue as it seems that zigbee2mqtt (1.3.1) is performing OK.

Koenkk · 2019-04-28T18:56:06Z

@uncle-fed thanks for posting the results here. good to hear it's working as expected now.

stale bot added the stale Stale issues label Jan 18, 2019

stale bot closed this as completed Jan 26, 2019

Koenkk reopened this Mar 23, 2019

stale bot removed the stale Stale issues label Mar 23, 2019

Koenkk added a commit that referenced this issue Mar 30, 2019

Add extra acceptDevIncoming logging. #538

2f52b85

Koenkk added a commit that referenced this issue Apr 1, 2019

Fix acceptDevIncoming. #538

32db1fd

Koenkk added this to the 1.4 milestone Apr 7, 2019

Koenkk closed this as completed Apr 28, 2019

wilmardo pushed a commit to wilmardo/zigbee2mqtt that referenced this issue Sep 26, 2019

Add extra acceptDevIncoming logging. Koenkk#538

96b30d4

wilmardo pushed a commit to wilmardo/zigbee2mqtt that referenced this issue Sep 26, 2019

Fix acceptDevIncoming. Koenkk#538

50beb67

rocket59 mentioned this issue Aug 20, 2021

Xiaomi devices join even though permit_join set to false #8406

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

permit_join false not honored #538

permit_join false not honored #538

dlashua commented Oct 25, 2018

tb-killa commented Oct 25, 2018

dlashua commented Nov 7, 2018

Underknowledge commented Nov 19, 2018

stale bot commented Jan 18, 2019

Fabiancrg commented Mar 11, 2019

uncle-fed commented Mar 23, 2019 •

edited

Loading

uncle-fed commented Mar 30, 2019 •

edited

Loading

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019

uncle-fed commented Mar 30, 2019 •

edited

Loading

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019 •

edited

Loading

Koenkk commented Apr 1, 2019

uncle-fed commented Apr 6, 2019

Koenkk commented Apr 19, 2019

uncle-fed commented Apr 19, 2019

Koenkk commented Apr 19, 2019

uncle-fed commented Apr 20, 2019

Koenkk commented Apr 22, 2019 •

edited

Loading

uncle-fed commented Apr 22, 2019

Koenkk commented Apr 22, 2019 •

edited

Loading

uncle-fed commented Apr 22, 2019 •

edited

Loading

Koenkk commented Apr 22, 2019 •

edited

Loading

uncle-fed commented Apr 22, 2019 •

edited

Loading

Koenkk commented Apr 22, 2019

uncle-fed commented Apr 27, 2019

Koenkk commented Apr 28, 2019

permit_join false not honored #538

permit_join false not honored #538

Comments

dlashua commented Oct 25, 2018

tb-killa commented Oct 25, 2018

dlashua commented Nov 7, 2018

Underknowledge commented Nov 19, 2018

stale bot commented Jan 18, 2019

Fabiancrg commented Mar 11, 2019

uncle-fed commented Mar 23, 2019 • edited Loading

uncle-fed commented Mar 30, 2019 • edited Loading

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019

uncle-fed commented Mar 30, 2019 • edited Loading

Koenkk commented Mar 30, 2019

uncle-fed commented Mar 30, 2019 • edited Loading

Koenkk commented Apr 1, 2019

uncle-fed commented Apr 6, 2019

Koenkk commented Apr 19, 2019

uncle-fed commented Apr 19, 2019

Koenkk commented Apr 19, 2019

uncle-fed commented Apr 20, 2019

Koenkk commented Apr 22, 2019 • edited Loading

uncle-fed commented Apr 22, 2019

Koenkk commented Apr 22, 2019 • edited Loading

uncle-fed commented Apr 22, 2019 • edited Loading

Koenkk commented Apr 22, 2019 • edited Loading

uncle-fed commented Apr 22, 2019 • edited Loading

Koenkk commented Apr 22, 2019

uncle-fed commented Apr 27, 2019

Koenkk commented Apr 28, 2019

uncle-fed commented Mar 23, 2019 •

edited

Loading

uncle-fed commented Mar 30, 2019 •

edited

Loading

uncle-fed commented Mar 30, 2019 •

edited

Loading

uncle-fed commented Mar 30, 2019 •

edited

Loading

Koenkk commented Apr 22, 2019 •

edited

Loading

Koenkk commented Apr 22, 2019 •

edited

Loading

uncle-fed commented Apr 22, 2019 •

edited

Loading

Koenkk commented Apr 22, 2019 •

edited

Loading

uncle-fed commented Apr 22, 2019 •

edited

Loading