2019-6-7 8:02:41 AM - info: Logging to directory: '/opt/zigbee2mqtt/data/log/2019-06-07.08-02-41'
2019-6-7 8:02:41 AM - debug: Removing old log directory '/opt/zigbee2mqtt/data/log/2019-06-06.21-43-57'
2019-6-7 8:02:42 AM - debug: Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[26],"precfgkey":"HIDDEN"},"dbPath":"/opt/zigbee2mqtt/data/database.db","coordBackupPath":"/opt/zigbee2mqtt/data/coordinator_backup.json","sp":{"baudRate":115200,"rtscts":true}}'
2019-6-7 8:02:42 AM - debug: Loaded state from file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:02:42 AM - debug: Saving state to file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:02:42 AM - info: Starting zigbee2mqtt version 1.4.0 (commit #8ad6aee)
2019-6-7 8:02:42 AM - info: Starting zigbee-shepherd
2019-6-7 8:02:44 AM - info: zigbee-shepherd started
2019-6-7 8:02:44 AM - info: Coordinator firmware version: '20190425'
2019-6-7 8:02:44 AM - debug: zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":"26","panId":65535,"extPanId":[0,0,18,25,34,56,75,170],"ieeeAddr":"0x00124b001938aa22","nwkAddr":0},"firmware":{"transportrev":2,"product":2,"version":"2.7.2","revision":20190425},"startTime":1559883764,"joinTimeLeft":0}
2019-6-7 8:02:44 AM - info: Currently 5 devices are joined:
2019-6-7 8:02:44 AM - info: 0x00124b0018015ee0 (0x00124b0018015ee0): TI0001 - Livolo Zigbee switch (1 and 2 gang) [work in progress](https://github.com/Koenkk/zigbee2mqtt/issues/592) (EndDevice)
2019-6-7 8:02:44 AM - info: 0x00124b0018029811 (0x00124b0018029811): TI0001 - Livolo Zigbee switch (1 and 2 gang) [work in progress](https://github.com/Koenkk/zigbee2mqtt/issues/592) (EndDevice)
2019-6-7 8:02:44 AM - info: 0x00124b0018035584 (0x00124b0018035584): TI0001 - Livolo Zigbee switch (1 and 2 gang) [work in progress](https://github.com/Koenkk/zigbee2mqtt/issues/592) (EndDevice)
2019-6-7 8:02:44 AM - info: 0x00124b00180292be (0x00124b00180292be): TI0001 - Livolo Zigbee switch (1 and 2 gang) [work in progress](https://github.com/Koenkk/zigbee2mqtt/issues/592) (EndDevice)
2019-6-7 8:02:44 AM - info: 0x00124b001838e896 (0x00124b001838e896): TI0001 - Livolo Zigbee switch (1 and 2 gang) [work in progress](https://github.com/Koenkk/zigbee2mqtt/issues/592) (EndDevice)
2019-6-7 8:02:44 AM - warn: `permit_join` set to  `true` in configuration.yaml.
2019-6-7 8:02:44 AM - warn: Allowing new devices to join.
2019-6-7 8:02:44 AM - warn: Set `permit_join` to `false` once you joined all devices.
2019-6-7 8:02:44 AM - info: Zigbee: allowing new devices to join.
2019-6-7 8:02:44 AM - info: Connecting to MQTT server at mqtt://localhost
2019-6-7 8:02:45 AM - debug: Soft reset timeout set to 3600 seconds
2019-6-7 8:02:45 AM - info: zigbee-shepherd ready
2019-6-7 8:02:45 AM - info: Connected to MQTT server
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018015ee0', payload '{"state_left":"OFF"}'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018029811', payload '{"state_left":"OFF"}'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018035584', payload '{"state_left":"OFF"}'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b00180292be', payload '{"state_left":"OFF"}'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b001838e896', payload '{"state_left":"OFF"}'
2019-6-7 8:02:45 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.4.0","commit":"8ad6aee","coordinator":20190425,"log_level":"debug","permit_join":true}'
2019-6-7 8:02:45 AM - debug: Mounted the cieApp (epId 11)
2019-6-7 8:03:25 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018015ee0/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:25 AM - info: Zigbee publish to device '0x00124b0018015ee0', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:25 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018015ee0', payload '{"state_left":"ON"}'
2019-6-7 8:03:27 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018015ee0/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:27 AM - info: Zigbee publish to device '0x00124b0018015ee0', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:28 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018015ee0', payload '{"state_left":"OFF"}'
2019-6-7 8:03:29 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b00180292be/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:29 AM - info: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:30 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b00180292be', payload '{"state_left":"ON"}'
2019-6-7 8:03:32 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b00180292be/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:32 AM - info: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:32 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b00180292be', payload '{"state_left":"OFF"}'
2019-6-7 8:03:34 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b001838e896/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:34 AM - info: Zigbee publish to device '0x00124b001838e896', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:34 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b001838e896', payload '{"state_left":"ON"}'
2019-6-7 8:03:36 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b001838e896/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:36 AM - info: Zigbee publish to device '0x00124b001838e896', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:40 AM - error: Zigbee publish to device '0x00124b001838e896', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 240. MAC transaction expired.
2019-6-7 8:03:40 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Error: AF data request fails, status code: 240. MAC transaction expired.","meta":{"entity":{"ID":"0x00124b001838e896","type":"device","friendlyName":"0x00124b001838e896"},"message":"{\"state\":\"OFF\"}"}}'
2019-6-7 8:03:40 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:41 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b001838e896/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:41 AM - info: Zigbee publish to device '0x00124b001838e896', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:41 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:41 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:41 AM - warn: No converter available for 'TI0001' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}'
2019-6-7 8:03:41 AM - warn: Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
2019-6-7 8:03:41 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b001838e896', payload '{"state_left":"OFF"}'
2019-6-7 8:03:41 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":0,"hwVersion":0,"dateCode":"20060831        "}}' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b001838e896"'
2019-6-7 8:03:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b001838e896"'
2019-6-7 8:03:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b001838e896"'
2019-6-7 8:03:42 AM - debug: Accept device incoming with ieeeAddr '0x00124b001838e896' permit join is 'true'
2019-6-7 8:03:42 AM - debug: Allowing device '0x00124b001838e896' to join
2019-6-7 8:03:42 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:42 AM - info: Device incoming...
2019-6-7 8:03:42 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
2019-6-7 8:03:42 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:03:44 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018035584/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:44 AM - info: Zigbee publish to device '0x00124b0018035584', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:44 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018035584', payload '{"state_left":"ON"}'
2019-6-7 8:03:46 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018035584/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:47 AM - info: Zigbee publish to device '0x00124b0018035584', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:47 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018035584', payload '{"state_left":"OFF"}'
2019-6-7 8:03:49 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018015ee0/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:50 AM - info: Zigbee publish to device '0x00124b0018015ee0', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:50 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018015ee0', payload '{"state_left":"ON"}'
2019-6-7 8:03:56 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018015ee0/left/set' with data '{"state":"OFF"}'
2019-6-7 8:03:56 AM - info: Zigbee publish to device '0x00124b0018015ee0', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:56 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018015ee0', payload '{"state_left":"OFF"}'
2019-6-7 8:03:58 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018029811/left/set' with data '{"state":"ON"}'
2019-6-7 8:03:59 AM - info: Zigbee publish to device '0x00124b0018029811', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:03:59 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018029811', payload '{"state_left":"ON"}'
2019-6-7 8:04:03 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b0018029811/left/set' with data '{"state":"OFF"}'
2019-6-7 8:04:04 AM - info: Zigbee publish to device '0x00124b0018029811', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:04:04 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b0018029811', payload '{"state_left":"OFF"}'
2019-6-7 8:04:07 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018035584"' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:08 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:08 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:08 AM - warn: No converter available for 'TI0001' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}'
2019-6-7 8:04:08 AM - warn: Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
2019-6-7 8:04:08 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":0,"hwVersion":0,"dateCode":"20060831        "}}' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:08 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018035584"'
2019-6-7 8:04:09 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018035584"'
2019-6-7 8:04:09 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018035584"'
2019-6-7 8:04:09 AM - debug: Accept device incoming with ieeeAddr '0x00124b0018035584' permit join is 'true'
2019-6-7 8:04:09 AM - debug: Allowing device '0x00124b0018035584' to join
2019-6-7 8:04:09 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x00124b0018035584"' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:09 AM - info: Device incoming...
2019-6-7 8:04:09 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
2019-6-7 8:04:09 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:04:32 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:04:43 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:44 AM - warn: No converter available for 'TI0001' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}'
2019-6-7 8:04:44 AM - warn: Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":0,"hwVersion":0,"dateCode":"20060831        "}}' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018029811"'
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018029811"'
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018029811"'
2019-6-7 8:04:44 AM - debug: Accept device incoming with ieeeAddr '0x00124b0018029811' permit join is 'true'
2019-6-7 8:04:44 AM - debug: Allowing device '0x00124b0018029811' to join
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:44 AM - info: Device incoming...
2019-6-7 8:04:44 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
2019-6-7 8:04:44 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:04:56 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:05:24 AM - info: Successfully reenabled joining
2019-6-7 8:05:40 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:42 AM - warn: No converter available for 'TI0001' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}'
2019-6-7 8:05:42 AM - warn: Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":0,"hwVersion":0,"dateCode":"20060831        "}}' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b00180292be"'
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b00180292be"'
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b00180292be"'
2019-6-7 8:05:42 AM - debug: Accept device incoming with ieeeAddr '0x00124b00180292be' permit join is 'true'
2019-6-7 8:05:42 AM - debug: Allowing device '0x00124b00180292be' to join
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:42 AM - info: Device incoming...
2019-6-7 8:05:42 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
2019-6-7 8:05:42 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:05:49 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:06:38 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:07:15 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:07:20 AM - debug: Received MQTT message on 'zigbee2mqtt/bridge/config/permit_join' with data 'true'
2019-6-7 8:07:20 AM - info: Zigbee: allowing new devices to join.
2019-6-7 8:07:20 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.4.0","commit":"8ad6aee","coordinator":20190425,"log_level":"debug","permit_join":true}'
2019-6-7 8:07:42 AM - debug: Saving state to file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:07:55 AM - debug: Received MQTT message on 'zigbee2mqtt/bridge/config/permit_join' with data 'true'
2019-6-7 8:07:55 AM - info: Zigbee: allowing new devices to join.
2019-6-7 8:07:55 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.4.0","commit":"8ad6aee","coordinator":20190425,"log_level":"debug","permit_join":true}'
2019-6-7 8:09:45 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:09:48 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:10:13 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b00180292be/left/set' with data '{"state":"ON"}'
2019-6-7 8:10:13 AM - info: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:10:15 AM - error: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null failed with error Error: AF data request fails, status code: 240. MAC transaction expired.
2019-6-7 8:10:15 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Error: AF data request fails, status code: 240. MAC transaction expired.","meta":{"entity":{"ID":"0x00124b00180292be","type":"device","friendlyName":"0x00124b00180292be"},"message":"{\"state\":\"ON\"}"}}'
2019-6-7 8:10:16 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:10:17 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b00180292be/left/set' with data '{"state":"ON"}'
2019-6-7 8:10:17 AM - info: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":108,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:10:17 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b00180292be', payload '{"state_left":"ON"}'
2019-6-7 8:10:22 AM - debug: Received MQTT message on 'zigbee2mqtt/0x00124b00180292be/left/set' with data '{"state":"OFF"}'
2019-6-7 8:10:22 AM - info: Zigbee publish to device '0x00124b00180292be', genLevelCtrl - moveToLevelWithOnOff - {"level":1,"transtime":1} - {"manufSpec":0,"disDefaultRsp":0} - null
2019-6-7 8:10:22 AM - info: MQTT publish: topic 'zigbee2mqtt/0x00124b00180292be', payload '{"state_left":"OFF"}'
2019-6-7 8:10:35 AM - info: Successfully reenabled joining
2019-6-7 8:10:36 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:10:58 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:11:24 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:11:38 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:12:18 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:28 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:30 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:37 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:42 AM - debug: Saving state to file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:12:47 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:47 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:12:56 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:12:57 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:13:03 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:13:07 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:13:10 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:13:12 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:13:15 AM - info: Successfully reenabled joining
2019-6-7 8:13:22 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:13:30 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:14:24 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:14:29 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:14:30 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:14:50 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:15:07 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:15:30 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:15:39 AM - debug: Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data ''
2019-6-7 8:15:39 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b001938aa22","type":"Coordinator"},{"ieeeAddr":"0x00124b0018015ee0","type":"EndDevice","model":"TI0001","friendly_name":"0x00124b0018015ee0","nwkAddr":3583,"manufId":0,"manufName":"LIVOLO\u0000\u0010TI0001  ","powerSource":"Mains (single phase)","modelId":"TI0001          ","hwVersion":0,"dateCode":"20060831        "},{"ieeeAddr":"0x00124b0018029811","type":"EndDevice","model":"TI0001","friendly_name":"0x00124b0018029811","nwkAddr":7943,"manufId":0,"manufName":"LIVOLO\u0000\u0010TI0001  ","powerSource":"Mains (single phase)","modelId":"TI0001          ","hwVersion":0,"dateCode":"20060831        "},{"ieeeAddr":"0x00124b0018035584","type":"EndDevice","model":"TI0001","friendly_name":"0x00124b0018035584","nwkAddr":65395,"manufId":0,"manufName":"LIVOLO\u0000\u0010TI0001  ","powerSource":"Mains (single phase)","modelId":"TI0001          ","hwVersion":0,"dateCode":"20060831        "},{"ieeeAddr":"0x00124b00180292be","type":"EndDevice","model":"TI0001","friendly_name":"0x00124b00180292be","nwkAddr":10666,"manufId":0,"manufName":"LIVOLO\u0000\u0010TI0001  ","powerSource":"Mains (single phase)","modelId":"TI0001          ","hwVersion":0,"dateCode":"20060831        "},{"ieeeAddr":"0x00124b001838e896","type":"EndDevice","model":"TI0001","friendly_name":"0x00124b001838e896","nwkAddr":56042,"manufId":0,"manufName":"LIVOLO\u0000\u0010TI0001  ","powerSource":"Mains (single phase)","modelId":"TI0001          ","hwVersion":0,"dateCode":"20060831        "}]}'
2019-6-7 8:15:55 AM - info: Successfully reenabled joining
2019-6-7 8:15:59 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:16:21 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:16:28 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:16:46 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:16:57 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:17:18 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:17:20 AM - debug: Received MQTT message on 'zigbee2mqtt/bridge/networkmap' with data 'raw'
2019-6-7 8:17:20 AM - info: Starting network scan...
2019-6-7 8:17:20 AM - debug: Preparing asynch network scan for '0x00124b001938aa22'
2019-6-7 8:17:20 AM - debug: Scanning device: '0x00124b001938aa22'
2019-6-7 8:17:20 AM - debug: All network map promises created
2019-6-7 8:17:23 AM - debug: Processing scan for: '0x00124b001938aa22'
2019-6-7 8:17:23 AM - debug: Processed device: '0x00124b001938aa22', linkSet: [{"ieeeAddr":"0x00124b0018035584","nwkAddr":65395,"lqi":3,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b001838e896","nwkAddr":56042,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b00180292be","nwkAddr":10666,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018029811","nwkAddr":7943,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018015ee0","nwkAddr":3583,"lqi":59,"depth":1,"parent":"0x00124b001938aa22"}]
2019-6-7 8:17:23 AM - info: Network scan completed
2019-6-7 8:17:23 AM - debug: Link map: [{"ieeeAddr":"0x00124b0018015ee0","nwkAddr":3583,"lqi":59,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b00180292be","nwkAddr":10666,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018029811","nwkAddr":7943,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018035584","nwkAddr":65395,"lqi":3,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b001838e896","nwkAddr":56042,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"}]
2019-6-7 8:17:23 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/networkmap/raw', payload '[{"ieeeAddr":"0x00124b0018015ee0","nwkAddr":3583,"lqi":59,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b00180292be","nwkAddr":10666,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018029811","nwkAddr":7943,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b0018035584","nwkAddr":65395,"lqi":3,"depth":1,"parent":"0x00124b001938aa22"},{"ieeeAddr":"0x00124b001838e896","nwkAddr":56042,"lqi":85,"depth":1,"parent":"0x00124b001938aa22"}]'
2019-6-7 8:17:42 AM - debug: Saving state to file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:17:48 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:18:02 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:18:35 AM - info: Successfully reenabled joining
2019-6-7 8:18:55 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018015ee0"' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:18:55 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018035584"' of device 'TI0001          ' (0x00124b0018035584) of endpoint 6
2019-6-7 8:18:56 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:18:57 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:18:57 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:18:57 AM - debug: Received zigbee message of type 'devChange' with data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:18:57 AM - warn: No converter available for 'TI0001' with cid 'genBasic', type 'devChange' and data '{"cid":"genBasic","data":{"manufacturerName":"LIVOLO\u0000\u0010TI0001  ","modelId":"TI0001          ","powerSource":1}}'
2019-6-7 8:18:57 AM - warn: Please see: https://www.zigbee2mqtt.io/how_tos/how_to_support_new_devices.html.
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'readRsp' with data '{"cid":"genBasic","data":{"zclVersion":0,"hwVersion":0,"dateCode":"20060831        "}}' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018015ee0"'
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018015ee0"'
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'devInterview' with data '"0x00124b0018015ee0"'
2019-6-7 8:18:58 AM - debug: Accept device incoming with ieeeAddr '0x00124b0018015ee0' permit join is 'true'
2019-6-7 8:18:58 AM - debug: Allowing device '0x00124b0018015ee0' to join
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'devIncoming' with data '"0x00124b0018015ee0"' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:18:58 AM - info: Device incoming...
2019-6-7 8:18:58 AM - info: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"device incoming"}'
2019-6-7 8:18:58 AM - debug: Received zigbee message of type 'devStatus' with data '"online"' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:19:04 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:09 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:14 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:19:30 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:35 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:43 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:48 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:19:53 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:20:33 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:20:33 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:20:43 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:20:46 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:20:49 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:20:58 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b001838e896"' of device 'TI0001          ' (0x00124b001838e896) of endpoint 6
2019-6-7 8:21:15 AM - info: Successfully reenabled joining
2019-6-7 8:21:48 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018015ee0"' of device 'TI0001          ' (0x00124b0018015ee0) of endpoint 6
2019-6-7 8:22:39 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b0018029811"' of device 'TI0001          ' (0x00124b0018029811) of endpoint 6
2019-6-7 8:22:42 AM - debug: Saving state to file /opt/zigbee2mqtt/data/state.json
2019-6-7 8:23:55 AM - info: Successfully reenabled joining
2019-6-7 8:24:50 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:24:50 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:25:03 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:25:06 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
2019-6-7 8:25:16 AM - debug: Received zigbee message of type 'endDeviceAnnce' with data '"0x00124b00180292be"' of device 'TI0001          ' (0x00124b00180292be) of endpoint 6
