zigbee2mqtt:info 5/9/2019, 10:10:49 PM Logging to directory: '/opt/zigbee2mqtt/data/log/2019-05-09.22-10-49'
  serialport/bindings loading LinuxBinding +0ms
  zigbee2mqtt:debug 5/9/2019, 10:10:50 PM Using zigbee-shepherd with settings: '{"net":{"panId":6754,"extPanId":[221,221,221,221,221,221,221,221],"channelList":[11],"precfgkey":"HIDDEN"},"dbPath":"/opt/zigbee2mqtt/data/database.db","sp":{"baudRate":115200,"rtscts":true}}'
  zigbee2mqtt:debug 5/9/2019, 10:10:50 PM Loaded state from file /opt/zigbee2mqtt/data/state.json
  zigbee2mqtt:debug 5/9/2019, 10:10:50 PM Saving state to file /opt/zigbee2mqtt/data/state.json
  zigbee2mqtt:info 5/9/2019, 10:10:50 PM Starting zigbee2mqtt version 1.3.1 (commit #39d6a8e)
  zigbee2mqtt:info 5/9/2019, 10:10:50 PM Starting zigbee-shepherd
  zigbee-shepherd:init zigbee-shepherd booting... +0ms
  cc-znp Initialize, opening serial port +0ms
  serialport/stream opening path: /dev/ttyACM0 +0ms
  serialport/binding-abstract open +0ms
  serialport/stream _read queueing _read for after open +6ms
  serialport/bindings/poller Creating poller +0ms
  serialport/stream opened path: /dev/ttyACM0 +10ms
  cc-znp The serialport /dev/ttyACM0 is opened. +19ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +20ms
  serialport/bindings/unixRead Starting read +0ms
  zigbee-shepherd:request REQ --> SYS:osalNvRead +0ms
  cc-znp:SREQ --> SYS:osalNvRead, { id: 3840, offset: 0, len: 1, value: [ 85 ] } +0ms
  serialport/stream _write 8 bytes of data +29ms
  serialport/binding-abstract write 8 bytes +29ms
  serialport/bindings/unixWrite Starting write 8 bytes offset 0 bytesToWrite 8 +0ms
  serialport/bindings/unixRead Finished read 146 bytes +33ms
  serialport/stream binding.read finished +8ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'permitJoinInd',
  cc-znp   payload: { duration: 0 },
  cc-znp   fcs: 143,
  cc-znp   csum: 143 } +58ms
  cc-znp { sof: 254,
  cc-znp   len: 3,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'mgmtPermitJoinRsp',
  cc-znp   payload: { srcaddr: 0, status: 0 },
  cc-znp   fcs: 240,
  cc-znp   csum: 240 } +9ms
  cc-znp { sof: 254,
  cc-znp   len: 58,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'incomingMsg',
  cc-znp   payload:
  cc-znp    { groupid: 0,
  cc-znp      clusterid: 0,
  cc-znp      srcaddr: 23185,
  cc-znp      srcendpoint: 1,
  cc-znp      dstendpoint: 1,
  cc-znp      wasbroadcast: 0,
  cc-znp      linkquality: 15,
  cc-znp      securityuse: 0,
  cc-znp      timestamp: 2091433,
  cc-znp      transseqnumber: 0,
  cc-znp      len: 38,
  cc-znp      data:
  cc-znp       <Buffer 18 02 0a 01 ff 42 1f 01 21 9f 0b 04 21 a8 13 05 21 0a 00 06 24 02 00 00 00 00 64 29 11 08 65 21 01 1d 0a 21 00 00> },
  cc-znp   fcs: 36,
  cc-znp   csum: 36 } +7ms
  cc-znp { sof: 254,
  cc-znp   len: 64,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'incomingMsg',
  cc-znp   payload:
  cc-znp    { groupid: 0,
  cc-znp      clusterid: 0,
  cc-znp      srcaddr: 27723,
  cc-znp      srcendpoint: 1,
  cc-znp      dstendpoint: 1,
  cc-znp      wasbroadcast: 0,
  cc-znp      linkquality: 44,
  cc-znp      securityuse: 0,
  cc-znp      timestamp: 2106692,
  cc-znp      transseqnumber: 0,
  cc-znp      len: 44,
  cc-znp      data:
  cc-znp       <Buffer 18 d4 0a 01 ff 42 25 01 21 d1 0b 04 21 a8 43 05 21 24 00 06 24 01 00 00 00 00 64 29 29 08 65 21 cd 1c 66 2b 85 88 01 00 0a 21 51 3f> },
  cc-znp   fcs: 36,
  cc-znp   csum: 36 } +8ms
  serialport/stream _read reading +48ms
  serialport/binding-abstract read +55ms
  serialport/bindings/unixRead Starting read +49ms
  serialport/bindings/unixWrite write returned null 8 +55ms
  serialport/bindings/unixWrite wrote 8 bytes +0ms
  serialport/bindings/unixWrite Finished writing 8 bytes +0ms
  serialport/stream binding.write write finished +3ms
  cc-znp:AREQ <-- ZDO:permitJoinInd, { duration: 0 } +0ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:permitJoinInd +0ms
  cc-znp:AREQ <-- ZDO:mgmtPermitJoinRsp, { srcaddr: 0, status: 0 } +2ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:mgmtPermitJoinRsp +2ms
  cc-znp:AREQ <-- AF:incomingMsg, { groupid: 0, clusterid: 0, srcaddr: 23185, srcendpoint: 1, dstendpoint: 1, wasbroadcast: 0, linkquality: 15, securityuse: 0, timestamp: 2091433, transseqnumber: 0, len: 38, data: <Buffer 18 02 0a 01 ff 42 1f 01 21 9f 0b 04 21 a8 13 05 21 0a 00 06 24 02 00 00 00 00 64 29 11 08 65 21 01 1d 0a 21 00 00> } +2ms
  zigbee-shepherd:msgHdlr IND <-- AF:incomingMsg, transId: 0 +2ms
  cc-znp:AREQ <-- AF:incomingMsg, { groupid: 0, clusterid: 0, srcaddr: 27723, srcendpoint: 1, dstendpoint: 1, wasbroadcast: 0, linkquality: 44, securityuse: 0, timestamp: 2106692, transseqnumber: 0, len: 44, data: <Buffer 18 d4 0a 01 ff 42 25 01 21 d1 0b 04 21 a8 43 05 21 24 00 06 24 01 00 00 00 00 64 29 29 08 65 21 cd 1c 66 2b 85 88 01 00 0a 21 51 3f> } +1ms
  zigbee-shepherd:msgHdlr IND <-- AF:incomingMsg, transId: 0 +2ms
  serialport/bindings/unixRead Finished read 8 bytes +12ms
  serialport/stream binding.read finished +10ms
  cc-znp { sof: 254,
  cc-znp   len: 3,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SYS',
  cc-znp   cmd: 'osalNvRead',
  cc-znp   payload: { status: 0, len: 1, value: <Buffer 55> },
  cc-znp   fcs: 62,
  cc-znp   csum: 62 } +21ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +19ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:SRSP <-- SYS:osalNvRead, { status: 0, len: 1, value: <Buffer 55> } +0ms
  zigbee-shepherd:request RSP <-- SYS:osalNvRead, status: 0 +103ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +5ms
  serialport/bindings/poller Polling for "readable" +115ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +18ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 131, len: 2, value: [ 98, 26 ] } +116ms
  serialport/stream _write 6 bytes of data +26ms
  serialport/binding-abstract write 6 bytes +26ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +44ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +1ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +26ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +28ms
  serialport/bindings/unixRead Finished read 10 bytes +0ms
  serialport/stream binding.read finished +4ms
  cc-znp { sof: 254,
  cc-znp   len: 5,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload: { status: 0, configid: 131, len: 2, value: <Buffer 62 1a> },
  cc-znp   fcs: 158,
  cc-znp   csum: 158 } +61ms
  serialport/stream _read reading +28ms
  serialport/binding-abstract read +29ms
  serialport/bindings/unixRead Starting read +29ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 131, len: 2, value: <Buffer 62 1a> } +65ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +46ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +8ms
  serialport/bindings/poller Polling for "readable" +38ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +12ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 45, len: 8, value: [ 221, 221, 221, 221, 221, 221, 221, 221 ] } +58ms
  serialport/stream _write 6 bytes of data +22ms
  serialport/binding-abstract write 6 bytes +22ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +55ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +19ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +20ms
  serialport/bindings/unixRead Finished read 16 bytes +1ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 11,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0,
  cc-znp      configid: 45,
  cc-znp      len: 8,
  cc-znp      value: <Buffer dd dd dd dd dd dd dd dd> },
  cc-znp   fcs: 76,
  cc-znp   csum: 76 } +37ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 45, len: 8, value: <Buffer dd dd dd dd dd dd dd dd> } +35ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +23ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +15ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +12ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 132, len: 4, value: [ 0, 8, 0, 0 ] } +34ms
  serialport/stream _write 6 bytes of data +20ms
  serialport/binding-abstract write 6 bytes +20ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +33ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +1ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +36ms
  serialport/binding-abstract read +22ms
  serialport/bindings/unixRead Starting read +37ms
  serialport/bindings/unixRead Finished read 12 bytes +2ms
  serialport/stream binding.read finished +24ms
  cc-znp { sof: 254,
  cc-znp   len: 7,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0, configid: 132, len: 4, value: <Buffer 00 08 00 00> },
  cc-znp   fcs: 237,
  cc-znp   csum: 237 } +54ms
  serialport/stream _read reading +7ms
  serialport/binding-abstract read +11ms
  serialport/bindings/unixRead Starting read +9ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 132, len: 4, value: <Buffer 00 08 00 00> } +51ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +39ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +3ms
  serialport/bindings/poller Polling for "readable" +16ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +13ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 98, len: 16, value: [ 1, 3, 5, 7, 9, 11, 13, 15, 0, 2, 4, 6, 8, 10, 12, 13 ] } +53ms
  serialport/stream _write 6 bytes of data +19ms
  serialport/binding-abstract write 6 bytes +20ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +51ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +35ms
  serialport/binding-abstract read +21ms
  serialport/bindings/unixRead Starting read +37ms
  serialport/bindings/unixRead Finished read 24 bytes +0ms
  serialport/stream binding.read finished +21ms
  cc-znp { sof: 254,
  cc-znp   len: 19,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload:
  cc-znp    { status: 0,
  cc-znp      configid: 98,
  cc-znp      len: 16,
  cc-znp      value: <Buffer 01 03 05 07 09 0b 0d 0f 00 02 04 06 08 0a 0c 0d> },
  cc-znp   fcs: 0,
  cc-znp   csum: 0 } +52ms
  serialport/stream _read reading +10ms
  serialport/binding-abstract read +11ms
  serialport/bindings/unixRead Starting read +12ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 98, len: 16, value: <Buffer 01 03 05 07 09 0b 0d 0f 00 02 04 06 08 0a 0c 0d> } +51ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +38ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +2ms
  serialport/bindings/poller Polling for "readable" +15ms
  zigbee-shepherd:request REQ --> SAPI:readConfiguration +12ms
  cc-znp:SREQ --> SAPI:readConfiguration, { configid: 99, len: 1, value: [ 0 ] } +50ms
  serialport/stream _write 6 bytes of data +16ms
  serialport/binding-abstract write 6 bytes +17ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +48ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +28ms
  serialport/binding-abstract read +14ms
  serialport/bindings/unixRead Starting read +29ms
  serialport/bindings/unixRead Finished read 9 bytes +0ms
  serialport/stream binding.read finished +14ms
  cc-znp { sof: 254,
  cc-znp   len: 4,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'readConfiguration',
  cc-znp   payload: { status: 0, configid: 99, len: 1, value: <Buffer 00> },
  cc-znp   fcs: 4,
  cc-znp   csum: 4 } +37ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- SAPI:readConfiguration, { status: 0, configid: 99, len: 1, value: <Buffer 00> } +37ms
  zigbee-shepherd:request RSP <-- SAPI:readConfiguration, status: 0 +24ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +2ms
  serialport/bindings/poller Polling for "readable" +8ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +18ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 0 } +42ms
  serialport/stream _write 6 bytes of data +22ms
  serialport/binding-abstract write 6 bytes +22ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +42ms
  serialport/bindings/unixWrite write returned null 6 +0ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +1ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +25ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +26ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +4ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 0, value: <Buffer 09 01 00 08 00 00 07 00> },
  cc-znp   fcs: 110,
  cc-znp   csum: 110 } +34ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 0, value: <Buffer 09 01 00 08 00 00 07 00> } +34ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +17ms
  zigbee-shepherd:init Now the ZNP is a coordinator. +0ms
  zigbee-shepherd:request REQ --> SYS:version +2ms
  cc-znp:SREQ --> SYS:version, {} +18ms
  serialport/stream _write 5 bytes of data +6ms
  serialport/binding-abstract write 5 bytes +6ms
  serialport/bindings/unixWrite Starting write 5 bytes offset 0 bytesToWrite 5 +17ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +14ms
  serialport/bindings/unixWrite write returned null 5 +1ms
  serialport/bindings/unixWrite wrote 5 bytes +0ms
  serialport/bindings/unixWrite Finished writing 5 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +4ms
  serialport/bindings/unixRead Finished read 19 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SYS',
  cc-znp   cmd: 'version',
  cc-znp   payload:
  cc-znp    { transportrev: 2,
  cc-znp      product: 0,
  cc-znp      majorrel: 2,
  cc-znp      minorrel: 6,
  cc-znp      maintrel: 3,
  cc-znp      revision: 20190223 },
  cc-znp   fcs: 68,
  cc-znp   csum: 68 } +16ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:SRSP <-- SYS:version, { transportrev: 2, product: 0, majorrel: 2, minorrel: 6, maintrel: 3, revision: 20190223 } +16ms
  zigbee-shepherd:request RSP <-- SYS:version +14ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +3ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 0 } +18ms
  serialport/stream _write 6 bytes of data +7ms
  serialport/binding-abstract write 6 bytes +7ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +16ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +8ms
  serialport/bindings/poller Polling for "readable" +15ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +4ms
  serialport/bindings/unixRead Starting read +3ms
  serialport/bindings/unixRead Finished read 14 bytes +1ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 0, value: <Buffer 09 01 00 08 00 00 07 00> },
  cc-znp   fcs: 110,
  cc-znp   csum: 110 } +18ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 0, value: <Buffer 09 01 00 08 00 00 07 00> } +18ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +14ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +1ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 1 } +15ms
  serialport/stream _write 6 bytes of data +4ms
  serialport/binding-abstract write 6 bytes +5ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +14ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +12ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +4ms
  serialport/bindings/unixRead Starting read +4ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 1, value: <Buffer 58 87 b8 14 00 4b 12 00> },
  cc-znp   fcs: 66,
  cc-znp   csum: 66 } +15ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 1, value: <Buffer 58 87 b8 14 00 4b 12 00> } +14ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +14ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +1ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 2 } +15ms
  serialport/stream _write 6 bytes of data +4ms
  serialport/binding-abstract write 6 bytes +5ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +14ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +12ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +4ms
  serialport/bindings/unixRead Starting read +4ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 2, value: <Buffer 00 00 b8 14 00 4b 12 00> },
  cc-znp   fcs: 158,
  cc-znp   csum: 158 } +15ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 2, value: <Buffer 00 00 b8 14 00 4b 12 00> } +16ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +14ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +1ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 5 } +15ms
  serialport/stream _write 6 bytes of data +4ms
  serialport/binding-abstract write 6 bytes +4ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +14ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +5ms
  serialport/bindings/poller Polling for "readable" +12ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +4ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 5, value: <Buffer 0b 00 b8 14 00 4b 12 00> },
  cc-znp   fcs: 146,
  cc-znp   csum: 146 } +15ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 5, value: <Buffer 0b 00 b8 14 00 4b 12 00> } +16ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +16ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +1ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 6 } +16ms
  serialport/stream _write 6 bytes of data +6ms
  serialport/binding-abstract write 6 bytes +5ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +15ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +13ms
  serialport/bindings/unixWrite write returned null 6 +2ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +5ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 6, value: <Buffer 62 1a b8 14 00 4b 12 00> },
  cc-znp   fcs: 226,
  cc-znp   csum: 226 } +18ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 6, value: <Buffer 62 1a b8 14 00 4b 12 00> } +17ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +16ms
  zigbee-shepherd:request REQ --> SAPI:getDeviceInfo +1ms
  cc-znp:SREQ --> SAPI:getDeviceInfo, { param: 7 } +18ms
  serialport/stream _write 6 bytes of data +5ms
  serialport/binding-abstract write 6 bytes +5ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +16ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +14ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +4ms
  serialport/bindings/unixRead Starting read +4ms
  serialport/bindings/unixRead Finished read 14 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 9,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'SAPI',
  cc-znp   cmd: 'getDeviceInfo',
  cc-znp   payload: { param: 7, value: <Buffer dd dd dd dd dd dd dd dd> },
  cc-znp   fcs: 110,
  cc-znp   csum: 110 } +16ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- SAPI:getDeviceInfo, { param: 7, value: <Buffer dd dd dd dd dd dd dd dd> } +16ms
  zigbee-shepherd:request RSP <-- SAPI:getDeviceInfo +14ms
  zigbee-shepherd:request REQ --> ZDO:nodeDescReq +4ms
  cc-znp:SREQ --> ZDO:nodeDescReq, { dstaddr: 0, nwkaddrofinterest: 0 } +20ms
  serialport/stream _write 9 bytes of data +10ms
  serialport/binding-abstract write 9 bytes +11ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +21ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +12ms
  serialport/bindings/poller Polling for "readable" +19ms
  serialport/bindings/unixWrite write returned null 9 +1ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +1ms
  serialport/stream binding.write write finished +4ms
  serialport/bindings/poller received "readable" +5ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 102,
  cc-znp   csum: 102 } +24ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:nodeDescReq, { status: 0 } +24ms
  serialport/bindings/unixRead Finished read 23 bytes +2ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 18,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      logicaltype_cmplxdescavai_userdescavai: 0,
  cc-znp      apsflags_freqband: 64,
  cc-znp      maccapflags: 143,
  cc-znp      manufacturercode: 0,
  cc-znp      maxbuffersize: 80,
  cc-znp      maxintransfersize: 160,
  cc-znp      servermask: 1,
  cc-znp      maxouttransfersize: 160,
  cc-znp      descriptorcap: 0 },
  cc-znp   fcs: 75,
  cc-znp   csum: 75 } +8ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:nodeDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, logicaltype_cmplxdescavai_userdescavai: 0, apsflags_freqband: 64, maccapflags: 143, manufacturercode: 0, maxbuffersize: 80, maxintransfersize: 160, servermask: 1, maxouttransfersize: 160, descriptorcap: 0 } +429ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:nodeDescRsp +428ms
  zigbee-shepherd:request REQ --> ZDO:activeEpReq +31ms
  cc-znp:SREQ --> ZDO:activeEpReq, { dstaddr: 0, nwkaddrofinterest: 0 } +29ms
  serialport/stream _write 9 bytes of data +7ms
  serialport/binding-abstract write 9 bytes +8ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +26ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +8ms
  serialport/bindings/poller Polling for "readable" +23ms
  serialport/bindings/unixWrite write returned null 9 +1ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +5ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 97,
  cc-znp   csum: 97 } +20ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:activeEpReq, { status: 0 } +27ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +1ms
  serialport/bindings/poller Polling for "readable" +7ms
  serialport/bindings/poller received "readable" +1ms
  serialport/binding-abstract read +2ms
  serialport/bindings/unixRead Starting read +1ms
  serialport/bindings/unixRead Finished read 18 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 13,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      activeepcount: 7,
  cc-znp      activeeplist: <Buffer 0b 06 05 04 03 02 01> },
  cc-znp   fcs: 198,
  cc-znp   csum: 198 } +8ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:AREQ <-- ZDO:activeEpRsp, { srcaddr: 0, status: 0, nwkaddr: 0, activeepcount: 7, activeeplist: <Buffer 0b 06 05 04 03 02 01> } +28ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:activeEpRsp +27ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +29ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 1 } +30ms
  serialport/stream _write 10 bytes of data +8ms
  serialport/binding-abstract write 10 bytes +9ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +28ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +10ms
  serialport/bindings/poller Polling for "readable" +16ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +1ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +22ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +30ms
  serialport/bindings/unixRead Finished read 19 bytes +1ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 1,
  cc-znp      profileid: 260,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 198,
  cc-znp   csum: 198 } +8ms
  serialport/stream _read reading +7ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +8ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 1, profileid: 260, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +30ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +31ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +29ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 2 } +28ms
  serialport/stream _write 10 bytes of data +6ms
  serialport/binding-abstract write 10 bytes +6ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +26ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +7ms
  serialport/bindings/poller Polling for "readable" +22ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +1ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +20ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +28ms
  serialport/bindings/unixRead Finished read 19 bytes +1ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 2,
  cc-znp      profileid: 257,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 192,
  cc-znp   csum: 192 } +7ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 2, profileid: 257, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +27ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +27ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +26ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 3 } +26ms
  serialport/stream _write 10 bytes of data +6ms
  serialport/binding-abstract write 10 bytes +5ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +24ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +20ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +1ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +5ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +18ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +25ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +1ms
  serialport/bindings/poller Polling for "readable" +7ms
  serialport/bindings/poller received "readable" +1ms
  serialport/binding-abstract read +2ms
  serialport/bindings/unixRead Starting read +1ms
  serialport/bindings/unixRead Finished read 19 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 3,
  cc-znp      profileid: 261,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 197,
  cc-znp   csum: 197 } +9ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 3, profileid: 261, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +27ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +27ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +26ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 4 } +26ms
  serialport/stream _write 10 bytes of data +5ms
  serialport/binding-abstract write 10 bytes +5ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +25ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +14ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +0ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +7ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +19ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +28ms
  serialport/bindings/unixRead Finished read 19 bytes +1ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 4,
  cc-znp      profileid: 263,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 192,
  cc-znp   csum: 192 } +10ms
  serialport/stream _read reading +10ms
  serialport/binding-abstract read +13ms
  serialport/bindings/unixRead Starting read +11ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 4, profileid: 263, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +31ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +31ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +33ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 5 } +33ms
  serialport/stream _write 10 bytes of data +10ms
  serialport/binding-abstract write 10 bytes +9ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +34ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +11ms
  serialport/bindings/poller Polling for "readable" +29ms
  serialport/bindings/unixWrite write returned null 10 +2ms
  serialport/bindings/unixWrite wrote 10 bytes +0ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +4ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +28ms
  serialport/stream _read reading +8ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +9ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +40ms
  serialport/bindings/unixRead Finished read 19 bytes +1ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 5,
  cc-znp      profileid: 264,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 206,
  cc-znp   csum: 206 } +13ms
  serialport/stream _read reading +11ms
  serialport/binding-abstract read +14ms
  serialport/bindings/unixRead Starting read +13ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 5, profileid: 264, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +42ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +42ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +41ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 6 } +42ms
  serialport/stream _write 10 bytes of data +9ms
  serialport/binding-abstract write 10 bytes +9ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +39ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +10ms
  serialport/bindings/poller Polling for "readable" +36ms
  serialport/bindings/unixWrite write returned null 10 +2ms
  serialport/bindings/unixWrite wrote 10 bytes +1ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +5ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +8ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +38ms
  serialport/stream _read reading +17ms
  serialport/binding-abstract read +20ms
  serialport/bindings/unixRead Starting read +19ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +52ms
  serialport/bindings/unixRead Finished read 19 bytes +2ms
  serialport/stream binding.read finished +4ms
  cc-znp { sof: 254,
  cc-znp   len: 14,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 8,
  cc-znp      endpoint: 6,
  cc-znp      profileid: 265,
  cc-znp      deviceid: 5,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 0,
  cc-znp      inclusterlist: <Buffer >,
  cc-znp      numoutclusters: 0,
  cc-znp      outclusterlist: <Buffer > },
  cc-znp   fcs: 204,
  cc-znp   csum: 204 } +15ms
  serialport/stream _read reading +11ms
  serialport/binding-abstract read +14ms
  serialport/bindings/unixRead Starting read +12ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 8, endpoint: 6, profileid: 265, deviceid: 5, deviceversion: 0, numinclusters: 0, inclusterlist: <Buffer >, numoutclusters: 0, outclusterlist: <Buffer > } +51ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +51ms
  zigbee-shepherd:request REQ --> ZDO:simpleDescReq +51ms
  cc-znp:SREQ --> ZDO:simpleDescReq, { dstaddr: 0, nwkaddrofinterest: 0, endpoint: 11 } +58ms
  serialport/stream _write 10 bytes of data +14ms
  serialport/binding-abstract write 10 bytes +14ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +54ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +16ms
  serialport/bindings/poller Polling for "readable" +50ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +0ms
  serialport/bindings/unixWrite Finished writing 10 bytes +1ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +7ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 96,
  cc-znp   csum: 96 } +29ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:simpleDescReq, { status: 0 } +41ms
  serialport/bindings/unixRead Finished read 31 bytes +1ms
  serialport/stream binding.read finished +1ms
  cc-znp { sof: 254,
  cc-znp   len: 26,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'simpleDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      len: 20,
  cc-znp      endpoint: 11,
  cc-znp      profileid: 260,
  cc-znp      deviceid: 1024,
  cc-znp      deviceversion: 0,
  cc-znp      numinclusters: 3,
  cc-znp      inclusterlist: <Buffer 00 00 01 05 03 00>,
  cc-znp      numoutclusters: 3,
  cc-znp      outclusterlist: <Buffer 00 05 02 05 03 00> },
  cc-znp   fcs: 195,
  cc-znp   csum: 195 } +8ms
  serialport/stream _read reading +7ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +8ms
  cc-znp:AREQ <-- ZDO:simpleDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, len: 20, endpoint: 11, profileid: 260, deviceid: 1024, deviceversion: 0, numinclusters: 3, inclusterlist: <Buffer 00 00 01 05 03 00>, numoutclusters: 3, outclusterlist: <Buffer 00 05 02 05 03 00> } +36ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:simpleDescRsp +36ms
  zigbee-shepherd:request REQ --> AF:delete +37ms
  cc-znp:SREQ --> AF:delete, { endpoint: 11 } +29ms
  serialport/stream _write 6 bytes of data +7ms
  serialport/binding-abstract write 6 bytes +6ms
  serialport/bindings/unixWrite Starting write 6 bytes offset 0 bytesToWrite 6 +26ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +7ms
  serialport/bindings/poller Polling for "readable" +22ms
  serialport/bindings/unixWrite write returned null 6 +1ms
  serialport/bindings/unixWrite wrote 6 bytes +0ms
  serialport/bindings/unixWrite Finished writing 6 bytes +1ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +3ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +4ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'delete',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 97,
  cc-znp   csum: 97 } +17ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- AF:delete, { status: 0 } +25ms
  zigbee-shepherd:request RSP <-- AF:delete, status: 0 +14ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +2ms
  serialport/bindings/poller Polling for "readable" +8ms
  zigbee-shepherd:init Deregister endpoint, epId: 11 +443ms
  zigbee-shepherd:request REQ --> ZDO:nodeDescReq +15ms
  cc-znp:SREQ --> ZDO:nodeDescReq, { dstaddr: 0, nwkaddrofinterest: 0 } +29ms
  serialport/stream _write 9 bytes of data +20ms
  serialport/binding-abstract write 9 bytes +19ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +28ms
  serialport/bindings/unixWrite write returned null 9 +0ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +1ms
  serialport/bindings/poller received "readable" +24ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +24ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +7ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 102,
  cc-znp   csum: 102 } +31ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:nodeDescReq, { status: 0 } +32ms
  serialport/bindings/unixRead Finished read 23 bytes +1ms
  serialport/stream binding.read finished +1ms
  cc-znp { sof: 254,
  cc-znp   len: 18,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      logicaltype_cmplxdescavai_userdescavai: 0,
  cc-znp      apsflags_freqband: 64,
  cc-znp      maccapflags: 143,
  cc-znp      manufacturercode: 0,
  cc-znp      maxbuffersize: 80,
  cc-znp      maxintransfersize: 160,
  cc-znp      servermask: 1,
  cc-znp      maxouttransfersize: 160,
  cc-znp      descriptorcap: 0 },
  cc-znp   fcs: 75,
  cc-znp   csum: 75 } +7ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:AREQ <-- ZDO:nodeDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, logicaltype_cmplxdescavai_userdescavai: 0, apsflags_freqband: 64, maccapflags: 143, manufacturercode: 0, maxbuffersize: 80, maxintransfersize: 160, servermask: 1, maxouttransfersize: 160, descriptorcap: 0 } +54ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:nodeDescRsp +54ms
  zigbee-shepherd:request REQ --> ZDO:activeEpReq +24ms
  cc-znp:SREQ --> ZDO:activeEpReq, { dstaddr: 0, nwkaddrofinterest: 0 } +24ms
  serialport/stream _write 9 bytes of data +5ms
  serialport/binding-abstract write 9 bytes +5ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +23ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +6ms
  serialport/bindings/poller Polling for "readable" +18ms
  serialport/bindings/unixWrite write returned null 9 +1ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +6ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 97,
  cc-znp   csum: 97 } +17ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +4ms
  cc-znp:SRSP <-- ZDO:activeEpReq, { status: 0 } +24ms
  serialport/bindings/unixRead Finished read 17 bytes +1ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 12,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      activeepcount: 6,
  cc-znp      activeeplist: <Buffer 06 05 04 03 02 01> },
  cc-znp   fcs: 205,
  cc-znp   csum: 205 } +7ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:AREQ <-- ZDO:activeEpRsp, { srcaddr: 0, status: 0, nwkaddr: 0, activeepcount: 6, activeeplist: <Buffer 06 05 04 03 02 01> } +24ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:activeEpRsp +24ms
  zigbee-shepherd:request REQ --> ZDO:mgmtPermitJoinReq +27ms
  cc-znp:SREQ --> ZDO:mgmtPermitJoinReq, { addrmode: 2, dstaddr: 0, duration: 0, tcsignificance: 0 } +27ms
  serialport/stream _write 10 bytes of data +8ms
  serialport/binding-abstract write 10 bytes +8ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +27ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +9ms
  serialport/bindings/poller Polling for "readable" +22ms
  serialport/bindings/unixWrite write returned null 10 +1ms
  serialport/bindings/unixWrite wrote 10 bytes +0ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +2ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +7ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'mgmtPermitJoinReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 82,
  cc-znp   csum: 82 } +21ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:SRSP <-- ZDO:mgmtPermitJoinReq, { status: 0 } +27ms
  serialport/bindings/unixRead Finished read 8 bytes +1ms
  serialport/stream binding.read finished +1ms
  cc-znp { sof: 254,
  cc-znp   len: 3,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'mgmtPermitJoinRsp',
  cc-znp   payload: { srcaddr: 0, status: 0 },
  cc-znp   fcs: 240,
  cc-znp   csum: 240 } +6ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +5ms
  cc-znp:AREQ <-- ZDO:mgmtPermitJoinRsp, { srcaddr: 0, status: 0 } +27ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:mgmtPermitJoinRsp +27ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +8ms
  serialport/bindings/poller Polling for "readable" +19ms
  zigbee-shepherd:init Loading devices from database done. +972ms
  zigbee-shepherd zigbee-shepherd is _ready and _enabled +0ms
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM zigbee-shepherd started
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM Coordinator firmware version: '20190223'
  zigbee2mqtt:debug 5/9/2019, 10:10:51 PM zigbee-shepherd info: {"enabled":true,"net":{"state":"Coordinator","channel":11,"panId":"0x1a62","extPanId":"0xdddddddddddddddd","ieeeAddr":"0x00124b0014b88758","nwkAddr":0},"firmware":{"transportrev":2,"product":0,"version":"2.6.3","revision":20190223},"startTime":1557432651,"joinTimeLeft":0}
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM Currently 0 devices are joined:
  zigbee2mqtt:warn 5/9/2019, 10:10:51 PM `permit_join` set to  `true` in configuration.yaml.
  zigbee2mqtt:warn 5/9/2019, 10:10:51 PM Allowing new devices to join.
  zigbee2mqtt:warn 5/9/2019, 10:10:51 PM Set `permit_join` to `false` once you joined all devices.
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM Zigbee: allowing new devices to join.
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM Connecting to MQTT server at mqtt://localhost
  zigbee-shepherd:request REQ --> ZDO:mgmtPermitJoinReq +255ms
  cc-znp:SREQ --> ZDO:mgmtPermitJoinReq, { addrmode: 15, dstaddr: 65532, duration: 255, tcsignificance: 0 } +255ms
  serialport/stream _write 10 bytes of data +236ms
  serialport/binding-abstract write 10 bytes +236ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +255ms
  serialport/bindings/unixWrite write returned null 10 +3ms
  serialport/bindings/unixWrite wrote 10 bytes +0ms
  serialport/bindings/unixWrite Finished writing 10 bytes +1ms
  serialport/stream binding.write write finished +6ms
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM zigbee-shepherd ready
  zigbee-shepherd:request REQ --> AF:register +14ms
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM Connected to MQTT server
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'online'
  serialport/bindings/poller received "readable" +315ms
  serialport/binding-abstract read +88ms
  serialport/bindings/unixRead Starting read +316ms
  serialport/bindings/unixRead Finished read 20 bytes +8ms
  serialport/stream binding.read finished +91ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'mgmtPermitJoinReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 82,
  cc-znp   csum: 82 } +338ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'permitJoinInd',
  cc-znp   payload: { duration: 255 },
  cc-znp   fcs: 112,
  cc-znp   csum: 112 } +4ms
  cc-znp { sof: 254,
  cc-znp   len: 3,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'mgmtPermitJoinRsp',
  cc-znp   payload: { srcaddr: 0, status: 0 },
  cc-znp   fcs: 240,
  cc-znp   csum: 240 } +4ms
  serialport/stream _read reading +14ms
  serialport/binding-abstract read +23ms
  serialport/bindings/unixRead Starting read +16ms
  zigbee2mqtt:debug 5/9/2019, 10:10:51 PM Received MQTT message on 'hass/status' with data 'online'
  cc-znp:SRSP <-- ZDO:mgmtPermitJoinReq, { status: 0 } +374ms
  cc-znp:AREQ <-- ZDO:permitJoinInd, { duration: 255 } +369ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:permitJoinInd +369ms
  cc-znp:AREQ <-- ZDO:mgmtPermitJoinRsp, { srcaddr: 0, status: 0 } +1ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:mgmtPermitJoinRsp +1ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +24ms
  serialport/bindings/poller Polling for "readable" +50ms
  cc-znp:SREQ --> AF:register, { endpoint: 11, appprofid: 260, appdeviceid: 1024, appdevver: 0, latencyreq: 0, appnuminclusters: 3, appinclusterlist: [ 0, 1281, 3 ], appnumoutclusters: 3, appoutclusterlist: [ 1280, 1282, 3 ] } +142ms
  serialport/stream _write 26 bytes of data +32ms
  serialport/binding-abstract write 26 bytes +33ms
  serialport/bindings/unixWrite Starting write 26 bytes offset 0 bytesToWrite 26 +138ms
  zigbee2mqtt:info 5/9/2019, 10:10:51 PM MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.3.1","commit":"39d6a8e","coordinator_firmware":20190223,"log_level":"debug","permit_join":true}'
  serialport/bindings/unixWrite write returned null 26 +6ms
  serialport/bindings/unixWrite wrote 26 bytes +0ms
  serialport/bindings/unixWrite Finished writing 26 bytes +0ms
  serialport/stream binding.write write finished +8ms
  serialport/bindings/poller received "readable" +14ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +16ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +1ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'register',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 101,
  cc-znp   csum: 101 } +47ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +6ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:SRSP <-- AF:register, { status: 0 } +26ms
  zigbee-shepherd:request RSP <-- AF:register, status: 0 +148ms
  zigbee-shepherd Register zApp, epId: 11, profId: 260  +362ms
  zigbee-shepherd:request REQ --> ZDO:nodeDescReq +2ms
  cc-znp:SREQ --> ZDO:nodeDescReq, { dstaddr: 0, nwkaddrofinterest: 0 } +22ms
  serialport/stream _write 9 bytes of data +7ms
  serialport/binding-abstract write 9 bytes +7ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +15ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +8ms
  serialport/bindings/poller Polling for "readable" +15ms
  serialport/bindings/unixWrite write returned null 9 +2ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +7ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 102,
  cc-znp   csum: 102 } +21ms
  serialport/stream _read reading +4ms
  serialport/binding-abstract read +5ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:SRSP <-- ZDO:nodeDescReq, { status: 0 } +21ms
  serialport/bindings/unixRead Finished read 23 bytes +1ms
  serialport/stream binding.read finished +2ms
  cc-znp { sof: 254,
  cc-znp   len: 18,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      logicaltype_cmplxdescavai_userdescavai: 0,
  cc-znp      apsflags_freqband: 64,
  cc-znp      maccapflags: 143,
  cc-znp      manufacturercode: 0,
  cc-znp      maxbuffersize: 80,
  cc-znp      maxintransfersize: 160,
  cc-znp      servermask: 1,
  cc-znp      maxouttransfersize: 160,
  cc-znp      descriptorcap: 0 },
  cc-znp   fcs: 75,
  cc-znp   csum: 75 } +8ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +8ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:nodeDescRsp, { srcaddr: 0, status: 0, nwkaddr: 0, logicaltype_cmplxdescavai_userdescavai: 0, apsflags_freqband: 64, maccapflags: 143, manufacturercode: 0, maxbuffersize: 80, maxintransfersize: 160, servermask: 1, maxouttransfersize: 160, descriptorcap: 0 } +53ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:nodeDescRsp +53ms
  zigbee-shepherd:request REQ --> ZDO:activeEpReq +28ms
  cc-znp:SREQ --> ZDO:activeEpReq, { dstaddr: 0, nwkaddrofinterest: 0 } +28ms
  serialport/stream _write 9 bytes of data +6ms
  serialport/binding-abstract write 9 bytes +6ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +26ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +7ms
  serialport/bindings/poller Polling for "readable" +22ms
  serialport/bindings/unixWrite write returned null 9 +1ms
  serialport/bindings/unixWrite wrote 9 bytes +1ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +9ms
  serialport/binding-abstract read +11ms
  serialport/bindings/unixRead Starting read +10ms
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +9ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 97,
  cc-znp   csum: 97 } +24ms
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +6ms
  cc-znp:SRSP <-- ZDO:activeEpReq, { status: 0 } +32ms
  serialport/bindings/unixRead Finished read 18 bytes +2ms
  serialport/stream binding.read finished +3ms
  cc-znp { sof: 254,
  cc-znp   len: 13,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'activeEpRsp',
  cc-znp   payload:
  cc-znp    { srcaddr: 0,
  cc-znp      status: 0,
  cc-znp      nwkaddr: 0,
  cc-znp      activeepcount: 7,
  cc-znp      activeeplist: <Buffer 0b 06 05 04 03 02 01> },
  cc-znp   fcs: 198,
  cc-znp   csum: 198 } +8ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:activeEpRsp, { srcaddr: 0, status: 0, nwkaddr: 0, activeepcount: 7, activeeplist: <Buffer 0b 06 05 04 03 02 01> } +32ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:activeEpRsp +32ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +5ms
  serialport/bindings/poller Polling for "readable" +21ms
  zigbee2mqtt:debug 5/9/2019, 10:10:51 PM Mounted the cieApp (epId 11)
  zigbee2mqtt:debug 5/9/2019, 10:10:52 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432652484'
  zigbee2mqtt:info 5/9/2019, 10:10:52 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:10:56 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432656484'
  zigbee2mqtt:info 5/9/2019, 10:10:56 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:11:00 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432660486'
  zigbee2mqtt:info 5/9/2019, 10:11:00 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:11:04 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432664486'
  zigbee2mqtt:info 5/9/2019, 10:11:04 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  serialport/bindings/poller received "readable" +15s
  serialport/binding-abstract read +15s
  serialport/bindings/unixRead Starting read +15s
  serialport/bindings/unixRead Finished read 18 bytes +1ms
  serialport/stream binding.read finished +15s
  cc-znp { sof: 254,
  cc-znp   len: 13,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'leaveInd',
  cc-znp   payload:
  cc-znp    { srcaddr: 40647,
  cc-znp      extaddr: '0x00158d0002ea057a',
  cc-znp      request: 0,
  cc-znp      removechildren: 0,
  cc-znp      rejoin: 0 },
  cc-znp   fcs: 215,
  cc-znp   csum: 215 } +15s
  serialport/stream _read reading +17ms
  serialport/binding-abstract read +20ms
  serialport/bindings/unixRead Starting read +18ms
  cc-znp:AREQ <-- ZDO:leaveInd, { srcaddr: 40647, extaddr: '0x00158d0002ea057a', request: 0, removechildren: 0, rejoin: 0 } +15s
  zigbee-shepherd:msgHdlr IND <-- ZDO:leaveInd +15s
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +4ms
  serialport/bindings/poller Polling for "readable" +26ms
  serialport/bindings/poller received "readable" +2s
  serialport/binding-abstract read +2s
  serialport/bindings/unixRead Starting read +2s
  serialport/bindings/unixRead Finished read 17 bytes +0ms
  serialport/stream binding.read finished +2s
  cc-znp { sof: 254,
  cc-znp   len: 12,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'tcDeviceInd',
  cc-znp   payload:
  cc-znp    { nwkaddr: 37936, extaddr: '0x00158d0002ea057a', parentaddr: 0 },
  cc-znp   fcs: 40,
  cc-znp   csum: 40 } +2s
  serialport/stream _read reading +9ms
  serialport/binding-abstract read +12ms
  serialport/bindings/unixRead Starting read +11ms
  cc-znp:AREQ <-- ZDO:tcDeviceInd, { nwkaddr: 37936, extaddr: '0x00158d0002ea057a', parentaddr: 0 } +2s
  zigbee-shepherd:msgHdlr IND <-- ZDO:tcDeviceInd +2s
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +4ms
  serialport/bindings/poller Polling for "readable" +16ms
  zigbee2mqtt:debug 5/9/2019, 10:11:08 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432668486'
  zigbee2mqtt:info 5/9/2019, 10:11:08 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  serialport/bindings/poller received "readable" +359ms
  serialport/binding-abstract read +363ms
  serialport/bindings/unixRead Starting read +360ms
  serialport/bindings/unixRead Finished read 18 bytes +0ms
  serialport/stream binding.read finished +365ms
  cc-znp { sof: 254,
  cc-znp   len: 13,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'endDeviceAnnceInd',
  cc-znp   payload:
  cc-znp    { srcaddr: 37936,
  cc-znp      nwkaddr: 37936,
  cc-znp      ieeeaddr: '0x00158d0002ea057a',
  cc-znp      capabilities: 128 },
  cc-znp   fcs: 6,
  cc-znp   csum: 6 } +372ms
  serialport/stream _read reading +6ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:AREQ <-- ZDO:endDeviceAnnceInd, { srcaddr: 37936, nwkaddr: 37936, ieeeaddr: '0x00158d0002ea057a', capabilities: 128 } +370ms
  zigbee-shepherd spinlock: false [] +0ms
  zigbee-shepherd:request REQ --> ZDO:nodeDescReq +17s
  cc-znp:SREQ --> ZDO:nodeDescReq, { dstaddr: 37936, nwkaddrofinterest: 37936 } +17s
  serialport/stream _write 9 bytes of data +7ms
  serialport/binding-abstract write 9 bytes +7ms
  zigbee-shepherd Device: 0x00158d0002ea057a endAnnounce. +0ms
  zigbee-shepherd:msgHdlr IND <-- ZDO:endDeviceAnnceInd +376ms
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +17s
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +9ms
  serialport/bindings/poller Polling for "readable" +17ms
  serialport/bindings/unixWrite write returned null 9 +1ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +0ms
  serialport/stream binding.write write finished +4ms
  serialport/bindings/poller received "readable" +8ms
  serialport/binding-abstract read +11ms
  serialport/bindings/unixRead Starting read +8ms
  serialport/bindings/unixRead Finished read 6 bytes +1ms
  serialport/stream binding.read finished +8ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 102,
  cc-znp   csum: 102 } +24ms
  serialport/stream _read reading +8ms
  serialport/binding-abstract read +9ms
  serialport/bindings/unixRead Starting read +8ms
  cc-znp:SRSP <-- ZDO:nodeDescReq, { status: 0 } +17s
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +2ms
  serialport/bindings/poller Polling for "readable" +11ms
  serialport/bindings/poller received "readable" +18ms
  serialport/binding-abstract read +20ms
  serialport/bindings/unixRead Starting read +19ms
  serialport/bindings/unixRead Finished read 82 bytes +0ms
  serialport/stream binding.read finished +22ms
  cc-znp { sof: 254,
  cc-znp   len: 45,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'incomingMsg',
  cc-znp   payload:
  cc-znp    { groupid: 0,
  cc-znp      clusterid: 0,
  cc-znp      srcaddr: 37936,
  cc-znp      srcendpoint: 1,
  cc-znp      dstendpoint: 1,
  cc-znp      wasbroadcast: 0,
  cc-znp      linkquality: 97,
  cc-znp      securityuse: 0,
  cc-znp      timestamp: 2765048,
  cc-znp      transseqnumber: 0,
  cc-znp      len: 25,
  cc-znp      data:
  cc-znp       <Buffer 18 00 0a 05 00 42 12 6c 75 6d 69 2e 73 65 6e 73 6f 72 5f 6d 61 67 6e 65 74> },
  cc-znp   fcs: 70,
  cc-znp   csum: 70 } +32ms
  cc-znp { sof: 254,
  cc-znp   len: 27,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'incomingMsg',
  cc-znp   payload:
  cc-znp    { groupid: 0,
  cc-znp      clusterid: 0,
  cc-znp      srcaddr: 37936,
  cc-znp      srcendpoint: 1,
  cc-znp      dstendpoint: 1,
  cc-znp      wasbroadcast: 0,
  cc-znp      linkquality: 97,
  cc-znp      securityuse: 0,
  cc-znp      timestamp: 2765063,
  cc-znp      transseqnumber: 0,
  cc-znp      len: 7,
  cc-znp      data: <Buffer 18 01 0a 01 00 20 0a> },
  cc-znp   fcs: 129,
  cc-znp   csum: 129 } +6ms
  serialport/stream _read reading +14ms
  serialport/binding-abstract read +17ms
  serialport/bindings/unixRead Starting read +16ms
  cc-znp:AREQ <-- AF:incomingMsg, { groupid: 0, clusterid: 0, srcaddr: 37936, srcendpoint: 1, dstendpoint: 1, wasbroadcast: 0, linkquality: 97, securityuse: 0, timestamp: 2765048, transseqnumber: 0, len: 25, data: <Buffer 18 00 0a 05 00 42 12 6c 75 6d 69 2e 73 65 6e 73 6f 72 5f 6d 61 67 6e 65 74> } +64ms
  zigbee-shepherd:af dispatchIncomingMsg(): type: incomingMsg, msg: {"groupid":0,"clusterid":0,"srcaddr":37936,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":97,"securityuse":0,"timestamp":2765048,"transseqnumber":0,"len":25,"data":{"type":"Buffer","data":[24,0,10,5,0,66,18,108,117,109,105,46,115,101,110,115,111,114,95,109,97,103,110,101,116]}} +0ms
  zigbee-shepherd:msgHdlr IND <-- AF:incomingMsg, transId: 0 +62ms
  cc-znp:AREQ <-- AF:incomingMsg, { groupid: 0, clusterid: 0, srcaddr: 37936, srcendpoint: 1, dstendpoint: 1, wasbroadcast: 0, linkquality: 97, securityuse: 0, timestamp: 2765063, transseqnumber: 0, len: 7, data: <Buffer 18 01 0a 01 00 20 0a> } +7ms
  zigbee-shepherd:af dispatchIncomingMsg(): type: incomingMsg, msg: {"groupid":0,"clusterid":0,"srcaddr":37936,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":97,"securityuse":0,"timestamp":2765063,"transseqnumber":0,"len":7,"data":{"type":"Buffer","data":[24,1,10,1,0,32,10]}} +4ms
  zigbee-shepherd:msgHdlr IND <-- AF:incomingMsg, transId: 0 +4ms
  serialport/bindings/unixRead Finished read 54 bytes +11ms
  serialport/stream binding.read finished +13ms
  cc-znp { sof: 254,
  cc-znp   len: 49,
  cc-znp   type: 'AREQ',
  cc-znp   subsys: 'AF',
  cc-znp   cmd: 'incomingMsg',
  cc-znp   payload:
  cc-znp    { groupid: 0,
  cc-znp      clusterid: 0,
  cc-znp      srcaddr: 37936,
  cc-znp      srcendpoint: 1,
  cc-znp      dstendpoint: 1,
  cc-znp      wasbroadcast: 0,
  cc-znp      linkquality: 97,
  cc-znp      securityuse: 0,
  cc-znp      timestamp: 2765075,
  cc-znp      transseqnumber: 0,
  cc-znp      len: 29,
  cc-znp      data:
  cc-znp       <Buffer 1c 34 12 02 0a 02 ff 4c 06 00 10 01 21 b3 0b 21 a8 01 24 00 00 00 00 00 21 4e 01 20 55> },
  cc-znp   fcs: 39,
  cc-znp   csum: 39 } +21ms
  serialport/stream _read reading +8ms
  serialport/binding-abstract read +20ms
  serialport/bindings/unixRead Starting read +10ms
  cc-znp:AREQ <-- AF:incomingMsg, { groupid: 0, clusterid: 0, srcaddr: 37936, srcendpoint: 1, dstendpoint: 1, wasbroadcast: 0, linkquality: 97, securityuse: 0, timestamp: 2765075, transseqnumber: 0, len: 29, data: <Buffer 1c 34 12 02 0a 02 ff 4c 06 00 10 01 21 b3 0b 21 a8 01 24 00 00 00 00 00 21 4e 01 20 55> } +13ms
  zigbee-shepherd:af dispatchIncomingMsg(): type: incomingMsg, msg: {"groupid":0,"clusterid":0,"srcaddr":37936,"srcendpoint":1,"dstendpoint":1,"wasbroadcast":0,"linkquality":97,"securityuse":0,"timestamp":2765075,"transseqnumber":0,"len":29,"data":{"type":"Buffer","data":[28,52,18,2,10,2,255,76,6,0,16,1,33,179,11,33,168,1,36,0,0,0,0,0,33,78,1,32,85]}} +12ms
  zigbee-shepherd:msgHdlr IND <-- AF:incomingMsg, transId: 0 +12ms
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +2ms
  serialport/bindings/poller Polling for "readable" +41ms
  zigbee2mqtt:debug 5/9/2019, 10:11:12 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432672487'
  zigbee2mqtt:info 5/9/2019, 10:11:12 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:11:16 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432676488'
  zigbee2mqtt:info 5/9/2019, 10:11:16 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee-shepherd:request REQ --> ZDO:nodeDescReq +10s
  cc-znp:SREQ --> ZDO:nodeDescReq, { dstaddr: 37936, nwkaddrofinterest: 37936 } +10s
  serialport/stream _write 9 bytes of data +10s
  serialport/binding-abstract write 9 bytes +10s
  serialport/bindings/unixWrite Starting write 9 bytes offset 0 bytesToWrite 9 +10s
  serialport/bindings/unixWrite write returned null 9 +0ms
  serialport/bindings/unixWrite wrote 9 bytes +0ms
  serialport/bindings/unixWrite Finished writing 9 bytes +1ms
  serialport/stream binding.write write finished +3ms
  serialport/bindings/poller received "readable" +10s
  serialport/binding-abstract read +14ms
  serialport/bindings/unixRead Starting read +10s
  serialport/bindings/unixRead Finished read 6 bytes +0ms
  serialport/stream binding.read finished +13ms
  cc-znp { sof: 254,
  cc-znp   len: 1,
  cc-znp   type: 'SRSP',
  cc-znp   subsys: 'ZDO',
  cc-znp   cmd: 'nodeDescReq',
  cc-znp   payload: { status: 0 },
  cc-znp   fcs: 102,
  cc-znp   csum: 102 } +10s
  serialport/stream _read reading +5ms
  serialport/binding-abstract read +7ms
  serialport/bindings/unixRead Starting read +7ms
  cc-znp:SRSP <-- ZDO:nodeDescReq, { status: 0 } +10s
  serialport/bindings/unixRead waiting for readable because of code: EAGAIN +1ms
  serialport/bindings/poller Polling for "readable" +15ms
  zigbee2mqtt:debug 5/9/2019, 10:11:20 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432680488'
  zigbee2mqtt:info 5/9/2019, 10:11:20 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:11:24 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432684489'
  zigbee2mqtt:info 5/9/2019, 10:11:24 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:debug 5/9/2019, 10:11:28 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432688490'
  zigbee2mqtt:info 5/9/2019, 10:11:28 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
  zigbee2mqtt:error 5/9/2019, 10:11:28 PM Cannot get the Node Descriptor of the Device: 0x00158d0002ea057a (Error: Timed out after 10000 ms)
  zigbee2mqtt:debug 5/9/2019, 10:11:32 PM Received MQTT message on 'zigbee2mqtt/bridge/config/devices' with data '1557432692490'
  zigbee2mqtt:info 5/9/2019, 10:11:32 PM MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"devices","message":[{"ieeeAddr":"0x00124b0014b88758","type":"Coordinator"}]}'
^C  zigbee2mqtt:debug 5/9/2019, 10:11:35 PM Saving state to file /opt/zigbee2mqtt/data/state.json
  zigbee2mqtt:info 5/9/2019, 10:11:35 PM MQTT publish: topic 'zigbee2mqtt/bridge/state', payload 'offline'
  zigbee2mqtt:info 5/9/2019, 10:11:35 PM Disconnecting from MQTT server
  zigbee-shepherd zigbee-shepherd is stopping. +44s
  serialport/stream #flush +17s
  serialport/binding-abstract flush +17s
  zigbee-shepherd:request REQ --> ZDO:mgmtPermitJoinReq +17s
  cc-znp:SREQ --> ZDO:mgmtPermitJoinReq, { addrmode: 15, dstaddr: 65532, duration: 0, tcsignificance: 0 } +17s
  serialport/stream _write 10 bytes of data +9ms
  serialport/binding-abstract write 10 bytes +8ms
  serialport/bindings/unixWrite Starting write 10 bytes offset 0 bytesToWrite 10 +17s
  serialport/stream binding.flush finished +11ms
  serialport/stream #close +2ms
  serialport/binding-abstract close +13ms
  serialport/bindings/poller Stopping poller +17s
  serialport/bindings/poller Destroying poller +2ms
  serialport/stream binding.read error { Error: Canceled
    at Poller.emitCanceled (/opt/zigbee2mqtt/node_modules/cc-znp/node_modules/@serialport/bindings/lib/poller.js:101:17)
    at Poller.stop (/opt/zigbee2mqtt/node_modules/cc-znp/node_modules/@serialport/bindings/lib/poller.js:91:10)
    at close.then (/opt/zigbee2mqtt/node_modules/cc-znp/node_modules/@serialport/bindings/lib/linux.js:48:19) canceled: true } +6ms
  serialport/stream _read queueing _read for after open +2ms
  serialport/bindings/unixWrite write returned null 10 +19ms
  serialport/bindings/unixWrite wrote 10 bytes +1ms
  serialport/bindings/unixWrite Finished writing 10 bytes +0ms
  serialport/stream binding.write write finished +3ms
  serialport/stream binding.close finished +7ms
  cc-znp The serialport /dev/ttyACM0 is closed. +17s
  zigbee-shepherd zigbee-shepherd is stopped. +50ms
  zigbee2mqtt:info 5/9/2019, 10:11:35 PM zigbee-shepherd stopped