In Mesh SDK 2.0.1 Light Switch Client demo is not working with interactive_pyaci

[Dev-Q0003]

I have followed the exact steps mentioned here http://infocenter.nordicsemi.com/index.jsp?topic=%2Fcom.nordic.infocenter.meshsdk.v2.0.1%2Fmd_scripts_interactive_pyaci_doc_demo_configuration.html&cp=4_1_0_2_0_2

But From Light Switch Client after successful provisioning configuration, button press events from Light Switch Client node is not sending it to Light Switch Server getting following messages in RTT viewer.  But any state change from Light switch Server will be received by Light Switch Client.

I'm not sure what went wrong, almost repeated the steps like fresh programming multiple times and followed the steps exactly but nothing works. It's Blocking the Gateway implementation

Hardware Setup:

1. nRF52832-DK1 Programmed with serial_nrf52832_xxAA_s132_6_0_0.emProject

2. nRF52832-DK2 Programmed with light_switch_server_nrf52832_xxAA_s132_6_0_0.emProject

3. nRF52832-DK3 Programmed with light_switch_client_nrf52832_xxAA_s132_6_0_0.emProject

Fullscreen 18-133-11-36_interactive_session.log Download

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

# IPython log file

db = MeshDB("database/example_database.json")

db.provisioners

p = Provisioner(device, db)

p.scan_start()

p.scan_stop()

p.provision(name="Light bulb")

cc = ConfigurationClient(db)

device.model_add(cc)

cc.publish_set(8, 0)

cc.composition_data_get()

cc.appkey_add(0)

cc.model_app_bind(db.nodes[0].unicast_address, 0, mt.ModelId(0, 0x59))

sc = SimpleOnOffClient()

device.model_add(sc)

sc.publish_set(0, 0)

sc.set(True)

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

# IPython log file


db = MeshDB("database/example_database.json")
db.provisioners
p = Provisioner(device, db)
p.scan_start()
p.scan_stop()
p.provision(name="Light bulb")
cc = ConfigurationClient(db)
device.model_add(cc)
cc.publish_set(8, 0)
cc.composition_data_get()
cc.appkey_add(0)
cc.model_app_bind(db.nodes[0].unicast_address, 0, mt.ModelId(0, 0x59))
sc = SimpleOnOffClient()
device.model_add(sc)
sc.publish_set(0, 0)
sc.set(True)
p.scan_start()
p.scan_stop()
p.provision(name="Light switch")
cc.publish_set(9, 1)
cc.composition_data_get()
cc.appkey_add(0)
cc.model_app_bind(db.nodes[1].unicast_address + 1, 0, mt.ModelId(1, 0x59))
cc.model_publication_set(db.nodes[1].unicast_address + 1, mt.ModelId(1, 0x59), mt.Publish(db.nodes[0].unicast_address, index=0, ttl=1))
cc.publish_set(8, 0)
cc.model_publication_set(db.nodes[0].unicast_address, mt.ModelId(0, 0x59), mt.Publish(db.groups[0].address, index=0, ttl=1))
cc.publish_set(9, 1)
cc.model_subscription_add(db.nodes[1].unicast_address + 1, db.groups[0].address, mt.ModelId(1, 0x59))
sc.set(True)
sc.set(False)
sc.set(True)
sc.set(False)
exit()

Fullscreen COM8_18-133-11-36_output.log Download

1

2

3

4

5

6

7

8

9

10

11

12

13

14

15

16

17

18

19

2018-05-13 11:37:34,944 - DEBUG - COM8: TX: 6169a8bebad2f3229fcc80a5e72577d6b5dd3209e06939661817baf38830f89e79390ba428b7a079ddad5cebef1fc59ef5efba02df74a5ba72e74370fe69121dbce69cd7d8cf7e2a7c64c3c9a57ef84ea24de0fda0adad9112a4370e7f2450cbc05e

2018-05-13 11:37:34,955 - DEBUG - COM8: RX: 03846900

2018-05-13 11:37:34,956 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 105, 'status': 0, 'data': bytearray(b'')}}

2018-05-13 11:37:34,957 - DEBUG - COM8: TX: 059f01000100

2018-05-13 11:37:34,956 - INFO - COM8: Success

2018-05-13 11:37:35,002 - DEBUG - COM8: RX: 03849f00

2018-05-13 11:37:35,018 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 159, 'status': 0, 'data': bytearray(b'')}}

2018-05-13 11:37:35,022 - DEBUG - COM8: TX: 1392000018eed9c2a56add85049ffc3c59ad0e12

2018-05-13 11:37:35,021 - INFO - COM8: Success

2018-05-13 11:37:35,026 - DEBUG - COM8: RX: 058492000000

2018-05-13 11:37:35,026 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 146, 'status': 0, 'data': bytearray(b'\x00\x00')}}

2018-05-13 11:37:35,027 - DEBUG - COM8: TX: 1597000000004f68ad85d9f48ac8589df665b6b49b8a

2018-05-13 11:37:35,026 - INFO - COM8: SubnetAdd: {'subnet_handle': 0}

2018-05-13 11:37:35,030 - DEBUG - COM8: RX: 058497000000

2018-05-13 11:37:35,030 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x00\x00')}}

2018-05-13 11:37:35,031 - DEBUG - COM8: TX: 1597010000002aa2a6ded5a0798ceab5787ca3ae39fc

2018-05-13 11:37:35,030 - INFO - COM8: AppkeyAdd: {'appkey_handle': 0}

2018-05-13 11:37:35,034 - DEBUG - COM8: RX: 058497000100

2018-05-13 11:37:35,034 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x01\x00')}}

XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX

2018-05-13 11:37:34,944 - DEBUG - COM8: TX: 6169a8bebad2f3229fcc80a5e72577d6b5dd3209e06939661817baf38830f89e79390ba428b7a079ddad5cebef1fc59ef5efba02df74a5ba72e74370fe69121dbce69cd7d8cf7e2a7c64c3c9a57ef84ea24de0fda0adad9112a4370e7f2450cbc05e
2018-05-13 11:37:34,955 - DEBUG - COM8: RX: 03846900
2018-05-13 11:37:34,956 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 105, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:37:34,957 - DEBUG - COM8: TX: 059f01000100
2018-05-13 11:37:34,956 - INFO - COM8: Success
2018-05-13 11:37:35,002 - DEBUG - COM8: RX: 03849f00
2018-05-13 11:37:35,018 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 159, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:37:35,022 - DEBUG - COM8: TX: 1392000018eed9c2a56add85049ffc3c59ad0e12
2018-05-13 11:37:35,021 - INFO - COM8: Success
2018-05-13 11:37:35,026 - DEBUG - COM8: RX: 058492000000
2018-05-13 11:37:35,026 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 146, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2018-05-13 11:37:35,027 - DEBUG - COM8: TX: 1597000000004f68ad85d9f48ac8589df665b6b49b8a
2018-05-13 11:37:35,026 - INFO - COM8: SubnetAdd: {'subnet_handle': 0}
2018-05-13 11:37:35,030 - DEBUG - COM8: RX: 058497000000
2018-05-13 11:37:35,030 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2018-05-13 11:37:35,031 - DEBUG - COM8: TX: 1597010000002aa2a6ded5a0798ceab5787ca3ae39fc
2018-05-13 11:37:35,030 - INFO - COM8: AppkeyAdd: {'appkey_handle': 0}
2018-05-13 11:37:35,034 - DEBUG - COM8: RX: 058497000100
2018-05-13 11:37:35,034 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x01\x00')}}
2018-05-13 11:37:35,034 - INFO - COM8: AppkeyAdd: {'appkey_handle': 1}
2018-05-13 11:37:53,223 - DEBUG - COM8: TX: 0161
2018-05-13 11:37:53,227 - DEBUG - COM8: RX: 03846100
2018-05-13 11:37:53,227 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 97, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:37:53,227 - INFO - COM8: Success
2018-05-13 11:37:54,052 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:37:54,052 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:37:54,053 - INFO - COM8: Received UUID 0059ffff0000000023ed93861a057ff9 with RSSI: -24 dB
2018-05-13 11:37:55,228 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd000016ac110b522d1
2018-05-13 11:37:55,229 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -48, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:37:55,229 - INFO - COM8: Received UUID 0059abcdefabcdefaccdefabcdefabcd with RSSI: -48 dB
2018-05-13 11:37:56,060 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e700013ee062b88de2
2018-05-13 11:37:56,060 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -25, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:37:57,237 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:37:57,237 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:37:58,062 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:37:58,062 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:37:59,241 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd800016ac110b522d1
2018-05-13 11:37:59,241 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -40, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:38:00,063 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e900013ee062b88de2
2018-05-13 11:38:00,063 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -23, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:01,241 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd000016ac110b522d1
2018-05-13 11:38:01,241 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -48, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:38:02,066 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e700013ee062b88de2
2018-05-13 11:38:02,066 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -25, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:03,245 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:38:03,245 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:38:04,075 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:38:04,075 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:06,084 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:38:06,084 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:08,092 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e700013ee062b88de2
2018-05-13 11:38:08,092 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -25, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:10,092 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:38:10,092 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:12,098 - DEBUG - COM8: RX: 1ac00059ffff0000000023ed93861a057ff9e800013ee062b88de2
2018-05-13 11:38:12,098 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xff\xff\x00\x00\x00\x00#\xed\x93\x86\x1a\x05\x7f\xf9'), 'rssi': -24, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2')}}
2018-05-13 11:38:13,794 - DEBUG - COM8: TX: 0162
2018-05-13 11:38:13,797 - DEBUG - COM8: RX: 03846200
2018-05-13 11:38:13,797 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 98, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:38:13,797 - INFO - COM8: Success
2018-05-13 11:38:23,361 - DEBUG - COM8: TX: 2c63000059ffff0000000023ed93861a057ff918eed9c2a56add85049ffc3c59ad0e1200000000000010000000
2018-05-13 11:38:23,367 - DEBUG - COM8: RX: 0484630000
2018-05-13 11:38:23,367 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 99, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:38:23,368 - INFO - COM8: Provision: {'context': 0}
2018-05-13 11:38:23,412 - DEBUG - COM8: RX: 02c100
2018-05-13 11:38:23,412 - DEBUG - COM8: parsed_packet {event: ProvLinkEstablished, data: {'context_id': 0}}
2018-05-13 11:38:23,412 - INFO - COM8: Link established
2018-05-13 11:38:23,446 - DEBUG - COM8: RX: 0bc300010001000000000000
2018-05-13 11:38:23,446 - DEBUG - COM8: parsed_packet {event: ProvCapsReceived, data: {'context_id': 0, 'num_elements': 1, 'public_key_type': 0, 'static_oob_types': 1, 'output_oob_size': 0, 'output_oob_actions': 0, 'input_oob_size': 0, 'input_oob_actions': 0}}
2018-05-13 11:38:23,447 - INFO - COM8: Received capabilities
2018-05-13 11:38:23,447 - INFO - COM8: Number of elements: 1
2018-05-13 11:38:23,448 - DEBUG - COM8: TX: 056600000000
2018-05-13 11:38:23,450 - DEBUG - COM8: RX: 0484660000
2018-05-13 11:38:23,450 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 102, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:38:23,450 - INFO - COM8: OobUse: {'context': 0}
2018-05-13 11:38:23,650 - DEBUG - COM8: RX: 62c700ab17c7b7a4dfca22094065b02c2229f0b989e31416cec9cc39cbadc9ce7b89fde4ce464934a0d0f80097d1a4a83f714481350287dddbb9cb5af0a7f9853fcee0a8bebad2f3229fcc80a5e72577d6b5dd3209e06939661817baf38830f89e7939
2018-05-13 11:38:23,650 - DEBUG - COM8: parsed_packet {event: ProvEcdhRequest, data: {'context_id': 0, 'peer_public': bytearray(b'\xab\x17\xc7\xb7\xa4\xdf\xca"\t@e\xb0,")\xf0\xb9\x89\xe3\x14\x16\xce\xc9\xcc9\xcb\xad\xc9\xce{\x89\xfd\xe4\xceFI4\xa0\xd0\xf8\x00\x97\xd1\xa4\xa8?qD\x815\x02\x87\xdd\xdb\xb9\xcbZ\xf0\xa7\xf9\x85?\xce\xe0'), 'node_private': bytearray(b'\xa8\xbe\xba\xd2\xf3"\x9f\xcc\x80\xa5\xe7%w\xd6\xb5\xdd2\t\xe0i9f\x18\x17\xba\xf3\x880\xf8\x9ey9')}}
2018-05-13 11:38:23,651 - INFO - COM8: ECDH request received
2018-05-13 11:38:23,655 - DEBUG - COM8: TX: 226800248b03be48bfec257b001742f4e3316663e3459f689703934ebc2894263209b5
2018-05-13 11:38:23,661 - DEBUG - COM8: RX: 0484680000
2018-05-13 11:38:23,661 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 104, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:38:23,661 - INFO - COM8: EcdhSecret: {'context': 0}
2018-05-13 11:38:23,998 - DEBUG - COM8: RX: 2cc500000000000000100000006ea2838180a9cc22c1f65582dc3e12c018eed9c2a56add85049ffc3c59ad0e12
2018-05-13 11:38:23,998 - DEBUG - COM8: parsed_packet {event: ProvComplete, data: {'context_id': 0, 'iv_index': 0, 'net_key_index': 0, 'address': 16, 'iv_update_flag': 0, 'key_refresh_flag': 0, 'device_key': bytearray(b'n\xa2\x83\x81\x80\xa9\xcc"\xc1\xf6U\x82\xdc>\x12\xc0'), 'net_key': bytearray(b'\x18\xee\xd9\xc2\xa5j\xdd\x85\x04\x9f\xfc<Y\xad\x0e\x12')}}
2018-05-13 11:38:23,999 - INFO - COM8: Provisioning complete
2018-05-13 11:38:24,000 - INFO - COM8: 	Address(es): 0x10-0x10
2018-05-13 11:38:24,001 - INFO - COM8: 	Device key: 6ea2838180a9cc22c1f65582dc3e12c0
2018-05-13 11:38:24,002 - INFO - COM8: 	Network key: 18eed9c2a56add85049ffc3c59ad0e12
2018-05-13 11:38:24,002 - INFO - COM8: Adding device key to subnet 0
2018-05-13 11:38:24,003 - DEBUG - COM8: TX: 159c100000006ea2838180a9cc22c1f65582dc3e12c0
2018-05-13 11:38:24,003 - INFO - COM8: Adding publication address of root element
2018-05-13 11:38:24,004 - DEBUG - COM8: TX: 03a41000
2018-05-13 11:38:24,008 - DEBUG - COM8: RX: 05849c000800
2018-05-13 11:38:24,008 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 156, 'status': 0, 'data': bytearray(b'\x08\x00')}}
2018-05-13 11:38:24,008 - INFO - COM8: DevkeyAdd: {'devkey_handle': 8}
2018-05-13 11:38:24,012 - DEBUG - COM8: RX: 0584a4000000
2018-05-13 11:38:24,012 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 164, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2018-05-13 11:38:24,012 - INFO - COM8: AddrPublicationAdd: {'address_handle': 0}
2018-05-13 11:38:24,106 - DEBUG - COM8: RX: 03c20000
2018-05-13 11:38:24,106 - DEBUG - COM8: parsed_packet {event: ProvLinkClosed, data: {'context_id': 0, 'close_reason': 0}}
2018-05-13 11:38:24,106 - INFO - COM8: Provisioning link closed
2018-05-13 11:39:02,544 - DEBUG - COM8.ConfigurationClient: Sending opcode: 8008, data: 00
2018-05-13 11:39:02,544 - DEBUG - COM8: TX: 0dab080001000000080000800800
2018-05-13 11:39:02,547 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:39:02,547 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:39:02,547 - INFO - COM8: Success
2018-05-13 11:39:02,641 - DEBUG - COM8: RX: 2cd0100001000800000004013ee062b88de2e71800020059000000000020000100000002010000020059000000
2018-05-13 11:39:02,641 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 4, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -25, 'actual_length': 24, 'data': bytearray(b'\x02\x00Y\x00\x00\x00\x00\x00 \x00\x01\x00\x00\x00\x02\x01\x00\x00\x02\x00Y\x00\x00\x00')}}
2018-05-13 11:39:02,646 - INFO - COM8.ConfigurationClient: Received composition data (page 0x00): {
  "cid": "0059",
  "pid": "0000",
  "vid": "0000",
  "crpl": 32,
  "features": {
    "relay": 0,
    "proxy": 2,
    "friend": 2,
    "low_power": 2
  },
  "elements": [
    {
      "index": 0,
      "location": "0000",
      "models": [
        {
          "modelId": "0000"
        },
        {
          "modelId": "0002"
        },
        {
          "modelId": "00590000"
        }
      ]
    }
  ]
}
2018-05-13 11:39:28,335 - DEBUG - COM8.ConfigurationClient: Sending opcode: 00, data: 0000004f68ad85d9f48ac8589df665b6b49b8a
2018-05-13 11:39:28,335 - DEBUG - COM8: TX: 1eab080001000000080000000000004f68ad85d9f48ac8589df665b6b49b8a
2018-05-13 11:39:28,340 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:39:28,341 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:39:28,341 - INFO - COM8: Success
2018-05-13 11:39:28,408 - DEBUG - COM8: RX: 1ad0100001000800000004013ee062b88de2e80600800300000000
2018-05-13 11:39:28,409 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 4, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -24, 'actual_length': 6, 'data': bytearray(b'\x80\x03\x00\x00\x00\x00')}}
2018-05-13 11:39:28,409 - INFO - COM8.ConfigurationClient: Appkey status: AccessStatus.SUCCESS
2018-05-13 11:39:28,414 - INFO - COM8.ConfigurationClient: Appkey add 0 succeded for subnet 0 at node 0010
2018-05-13 11:39:42,640 - DEBUG - COM8.ConfigurationClient: Sending opcode: 803d, data: 1000000059000000
2018-05-13 11:39:42,641 - DEBUG - COM8: TX: 14ab080001000000080000803d1000000059000000
2018-05-13 11:39:42,645 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:39:42,645 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:39:42,645 - INFO - COM8: Success
2018-05-13 11:39:42,691 - DEBUG - COM8: RX: 1fd0100001000800000004013ee062b88de2e80b00803e001000000059000000
2018-05-13 11:39:42,691 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 4, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -24, 'actual_length': 11, 'data': bytearray(b'\x80>\x00\x10\x00\x00\x00Y\x00\x00\x00')}}
2018-05-13 11:39:42,692 - INFO - COM8.ConfigurationClient: Model app bind status: AccessStatus.SUCCESS
2018-05-13 11:39:42,696 - INFO - COM8.ConfigurationClient: Appkey bind 0 to model 00590000 at 0010
2018-05-13 11:40:20,637 - DEBUG - COM8.SimpleOnOffClient: Sending opcode: c10059, data: 0100
2018-05-13 11:40:20,637 - DEBUG - COM8: TX: 0fab000001000000080000c100590100
2018-05-13 11:40:20,640 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:40:20,640 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:40:20,641 - INFO - COM8: Success
2018-05-13 11:40:20,687 - DEBUG - COM8: RX: 18d0100001000000000004013ee062b88de2e70400c4005901
2018-05-13 11:40:20,687 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 0, 'subnet_handle': 0, 'ttl': 4, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -25, 'actual_length': 4, 'data': bytearray(b'\xc4\x00Y\x01')}}
2018-05-13 11:40:20,688 - DEBUG - COM8: Message Opcode bytearray(b'\xc4\x00Y'), Data bytearray(b'\x01') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 11:40:20,688 - INFO - COM8.SimpleOnOffClient: Present value is on
2018-05-13 11:40:40,285 - DEBUG - COM8: TX: 0161
2018-05-13 11:40:40,288 - DEBUG - COM8: RX: 03846100
2018-05-13 11:40:40,288 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 97, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:40:40,288 - INFO - COM8: Success
2018-05-13 11:40:41,024 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdda00016ac110b522d1
2018-05-13 11:40:41,024 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -38, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:43,032 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd100016ac110b522d1
2018-05-13 11:40:43,032 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -47, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:45,036 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddc00016ac110b522d1
2018-05-13 11:40:45,036 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -36, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:47,035 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd900016ac110b522d1
2018-05-13 11:40:47,035 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -39, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:49,044 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd000016ac110b522d1
2018-05-13 11:40:49,044 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -48, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:51,048 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddc00016ac110b522d1
2018-05-13 11:40:51,048 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -36, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:53,051 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdda00016ac110b522d1
2018-05-13 11:40:53,051 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -38, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:55,058 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd100016ac110b522d1
2018-05-13 11:40:55,058 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -47, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:57,058 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddc00016ac110b522d1
2018-05-13 11:40:57,058 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -36, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:40:59,063 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdd800016ac110b522d1
2018-05-13 11:40:59,063 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -40, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:01,627 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdda00016ac110b522d1
2018-05-13 11:41:01,627 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -38, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:03,634 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:41:03,634 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:05,639 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddf00016ac110b522d1
2018-05-13 11:41:05,639 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -33, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:07,648 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdda00016ac110b522d1
2018-05-13 11:41:07,648 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -38, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:09,653 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:41:09,653 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:11,662 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:41:11,662 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:13,668 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcdda00016ac110b522d1
2018-05-13 11:41:13,668 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -38, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:15,672 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:41:15,672 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:17,680 - DEBUG - COM8: RX: 1ac00059abcdefabcdefaccdefabcdefabcddd00016ac110b522d1
2018-05-13 11:41:17,681 - DEBUG - COM8: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x00Y\xab\xcd\xef\xab\xcd\xef\xac\xcd\xef\xab\xcd\xef\xab\xcd'), 'rssi': -35, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1')}}
2018-05-13 11:41:18,829 - DEBUG - COM8: TX: 0162
2018-05-13 11:41:18,833 - DEBUG - COM8: RX: 03846200
2018-05-13 11:41:18,833 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 98, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:41:18,834 - INFO - COM8: Success
2018-05-13 11:41:24,975 - DEBUG - COM8: TX: 2c63000059abcdefabcdefaccdefabcdefabcd18eed9c2a56add85049ffc3c59ad0e1200000000000011000000
2018-05-13 11:41:24,982 - DEBUG - COM8: RX: 0484630000
2018-05-13 11:41:24,982 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 99, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:41:24,982 - INFO - COM8: Provision: {'context': 0}
2018-05-13 11:41:25,030 - DEBUG - COM8: RX: 02c100
2018-05-13 11:41:25,030 - DEBUG - COM8: parsed_packet {event: ProvLinkEstablished, data: {'context_id': 0}}
2018-05-13 11:41:25,030 - INFO - COM8: Link established
2018-05-13 11:41:25,047 - DEBUG - COM8: RX: 0bc300050001000000000000
2018-05-13 11:41:25,047 - DEBUG - COM8: parsed_packet {event: ProvCapsReceived, data: {'context_id': 0, 'num_elements': 5, 'public_key_type': 0, 'static_oob_types': 1, 'output_oob_size': 0, 'output_oob_actions': 0, 'input_oob_size': 0, 'input_oob_actions': 0}}
2018-05-13 11:41:25,047 - INFO - COM8: Received capabilities
2018-05-13 11:41:25,048 - INFO - COM8: Number of elements: 5
2018-05-13 11:41:25,049 - DEBUG - COM8: TX: 056600000000
2018-05-13 11:41:25,051 - DEBUG - COM8: RX: 0484660000
2018-05-13 11:41:25,051 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 102, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:41:25,051 - INFO - COM8: OobUse: {'context': 0}
2018-05-13 11:41:25,242 - DEBUG - COM8: RX: 62c70047ab2a3430b036e31c7f670b366f69e826e9511a6138511d83ad6b5dbefbe797dabfa4b3f65662161f9ec01e35fdbe97ed9344f3e49a072651291161e4115b4ca8bebad2f3229fcc80a5e72577d6b5dd3209e06939661817baf38830f89e7939
2018-05-13 11:41:25,242 - DEBUG - COM8: parsed_packet {event: ProvEcdhRequest, data: {'context_id': 0, 'peer_public': bytearray(b'G\xab*40\xb06\xe3\x1c\x7fg\x0b6oi\xe8&\xe9Q\x1aa8Q\x1d\x83\xadk]\xbe\xfb\xe7\x97\xda\xbf\xa4\xb3\xf6Vb\x16\x1f\x9e\xc0\x1e5\xfd\xbe\x97\xed\x93D\xf3\xe4\x9a\x07&Q)\x11a\xe4\x11[L'), 'node_private': bytearray(b'\xa8\xbe\xba\xd2\xf3"\x9f\xcc\x80\xa5\xe7%w\xd6\xb5\xdd2\t\xe0i9f\x18\x17\xba\xf3\x880\xf8\x9ey9')}}
2018-05-13 11:41:25,242 - INFO - COM8: ECDH request received
2018-05-13 11:41:25,244 - DEBUG - COM8: TX: 226800f4537d6529913a3f8c470785b87e7fa49afc6162946f690c9e073fa8aa6f25cb
2018-05-13 11:41:25,249 - DEBUG - COM8: RX: 0484680000
2018-05-13 11:41:25,249 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 104, 'status': 0, 'data': bytearray(b'\x00')}}
2018-05-13 11:41:25,249 - INFO - COM8: EcdhSecret: {'context': 0}
2018-05-13 11:41:25,612 - DEBUG - COM8: RX: 2cc50000000000000011000000b7fcea4af364f66972e134e1bdc4a53b18eed9c2a56add85049ffc3c59ad0e12
2018-05-13 11:41:25,612 - DEBUG - COM8: parsed_packet {event: ProvComplete, data: {'context_id': 0, 'iv_index': 0, 'net_key_index': 0, 'address': 17, 'iv_update_flag': 0, 'key_refresh_flag': 0, 'device_key': bytearray(b'\xb7\xfc\xeaJ\xf3d\xf6ir\xe14\xe1\xbd\xc4\xa5;'), 'net_key': bytearray(b'\x18\xee\xd9\xc2\xa5j\xdd\x85\x04\x9f\xfc<Y\xad\x0e\x12')}}
2018-05-13 11:41:25,612 - INFO - COM8: Provisioning complete
2018-05-13 11:41:25,614 - INFO - COM8: 	Address(es): 0x11-0x15
2018-05-13 11:41:25,615 - INFO - COM8: 	Device key: b7fcea4af364f66972e134e1bdc4a53b
2018-05-13 11:41:25,615 - INFO - COM8: 	Network key: 18eed9c2a56add85049ffc3c59ad0e12
2018-05-13 11:41:25,616 - INFO - COM8: Adding device key to subnet 0
2018-05-13 11:41:25,617 - DEBUG - COM8: TX: 159c11000000b7fcea4af364f66972e134e1bdc4a53b
2018-05-13 11:41:25,617 - INFO - COM8: Adding publication address of root element
2018-05-13 11:41:25,618 - DEBUG - COM8: TX: 03a41100
2018-05-13 11:41:25,622 - DEBUG - COM8: RX: 05849c000900
2018-05-13 11:41:25,623 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 156, 'status': 0, 'data': bytearray(b'\t\x00')}}
2018-05-13 11:41:25,623 - INFO - COM8: DevkeyAdd: {'devkey_handle': 9}
2018-05-13 11:41:25,624 - DEBUG - COM8: RX: 0584a4000100
2018-05-13 11:41:25,624 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 164, 'status': 0, 'data': bytearray(b'\x01\x00')}}
2018-05-13 11:41:25,624 - INFO - COM8: AddrPublicationAdd: {'address_handle': 1}
2018-05-13 11:41:25,740 - DEBUG - COM8: RX: 03c20000
2018-05-13 11:41:25,740 - DEBUG - COM8: parsed_packet {event: ProvLinkClosed, data: {'context_id': 0, 'close_reason': 0}}
2018-05-13 11:41:25,740 - INFO - COM8: Provisioning link closed
2018-05-13 11:41:48,060 - DEBUG - COM8.ConfigurationClient: Sending opcode: 8008, data: 00
2018-05-13 11:41:48,060 - DEBUG - COM8: TX: 0dab090001000100080000800800
2018-05-13 11:41:48,065 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:41:48,065 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:41:48,066 - INFO - COM8: Success
2018-05-13 11:41:48,189 - DEBUG - COM8: RX: 48d011000100090000001e016ac110b522d1de340002005900000000002000010000000200000002000000000159000100000000015900010000000001590001000000000159000100
2018-05-13 11:41:48,189 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 17, 'dst': 1, 'appkey_handle': 9, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1'), 'rssi': -34, 'actual_length': 52, 'data': bytearray(b'\x02\x00Y\x00\x00\x00\x00\x00 \x00\x01\x00\x00\x00\x02\x00\x00\x00\x02\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00')}}
2018-05-13 11:41:48,196 - INFO - COM8.ConfigurationClient: Received composition data (page 0x00): {
  "cid": "0059",
  "pid": "0000",
  "vid": "0000",
  "crpl": 32,
  "features": {
    "relay": 0,
    "proxy": 2,
    "friend": 2,
    "low_power": 2
  },
  "elements": [
    {
      "index": 0,
      "location": "0000",
      "models": [
        {
          "modelId": "0000"
        },
        {
          "modelId": "0002"
        }
      ]
    },
    {
      "index": 1,
      "location": "0000",
      "models": [
        {
          "modelId": "00590001"
        }
      ]
    },
    {
      "index": 2,
      "location": "0000",
      "models": [
        {
          "modelId": "00590001"
        }
      ]
    },
    {
      "index": 3,
      "location": "0000",
      "models": [
        {
          "modelId": "00590001"
        }
      ]
    },
    {
      "index": 4,
      "location": "0000",
      "models": [
        {
          "modelId": "00590001"
        }
      ]
    }
  ]
}
2018-05-13 11:41:48,208 - DEBUG - COM8: Message Opcode bytearray(b'\x02'), Data bytearray(b'\x00Y\x00\x00\x00\x00\x00 \x00\x01\x00\x00\x00\x02\x00\x00\x00\x02\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00\x00\x00\x00\x01Y\x00\x01\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 11:42:01,069 - DEBUG - COM8.ConfigurationClient: Sending opcode: 00, data: 0000004f68ad85d9f48ac8589df665b6b49b8a
2018-05-13 11:42:01,070 - DEBUG - COM8: TX: 1eab090001000100080000000000004f68ad85d9f48ac8589df665b6b49b8a
2018-05-13 11:42:01,075 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:42:01,075 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:42:01,076 - INFO - COM8: Success
2018-05-13 11:42:01,150 - DEBUG - COM8: RX: 1ad011000100090000001e016ac110b522d1de0600800300000000
2018-05-13 11:42:01,151 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 17, 'dst': 1, 'appkey_handle': 9, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1'), 'rssi': -34, 'actual_length': 6, 'data': bytearray(b'\x80\x03\x00\x00\x00\x00')}}
2018-05-13 11:42:01,151 - INFO - COM8.ConfigurationClient: Appkey status: AccessStatus.SUCCESS
2018-05-13 11:42:01,157 - INFO - COM8.ConfigurationClient: Appkey add 0 succeded for subnet 0 at node 0011
2018-05-13 11:42:01,158 - DEBUG - COM8: Message Opcode bytearray(b'\x80\x03'), Data bytearray(b'\x00\x00\x00\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 11:42:15,550 - DEBUG - COM8.ConfigurationClient: Sending opcode: 803d, data: 1200000059000100
2018-05-13 11:42:15,551 - DEBUG - COM8: TX: 14ab090001000100080000803d1200000059000100
2018-05-13 11:42:15,555 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:42:15,555 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:42:15,556 - INFO - COM8: Success
2018-05-13 11:42:15,600 - DEBUG - COM8: RX: 1fd011000100090000001e016ac110b522d1d90b00803e001200000059000100
2018-05-13 11:42:15,601 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 17, 'dst': 1, 'appkey_handle': 9, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1'), 'rssi': -39, 'actual_length': 11, 'data': bytearray(b'\x80>\x00\x12\x00\x00\x00Y\x00\x01\x00')}}
2018-05-13 11:42:15,602 - INFO - COM8.ConfigurationClient: Model app bind status: AccessStatus.SUCCESS
2018-05-13 11:42:15,608 - INFO - COM8.ConfigurationClient: Appkey bind 0 to model 00590001 at 0012
2018-05-13 11:42:15,609 - DEBUG - COM8: Message Opcode bytearray(b'\x80>'), Data bytearray(b'\x00\x12\x00\x00\x00Y\x00\x01\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 11:42:36,243 - DEBUG - COM8.ConfigurationClient: Sending opcode: 03, data: 12001000000001000059000100
2018-05-13 11:42:36,244 - DEBUG - COM8: TX: 18ab0900010001000800000312001000000001000059000100
2018-05-13 11:42:36,248 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:42:36,248 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:42:36,249 - INFO - COM8: Success
2018-05-13 11:42:36,349 - DEBUG - COM8: RX: 24d011000100090000001e016ac110b522d1de100080190012001000000001000059000100
2018-05-13 11:42:36,350 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 17, 'dst': 1, 'appkey_handle': 9, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1'), 'rssi': -34, 'actual_length': 16, 'data': bytearray(b'\x80\x19\x00\x12\x00\x10\x00\x00\x00\x01\x00\x00Y\x00\x01\x00')}}
2018-05-13 11:42:36,350 - INFO - COM8.ConfigurationClient: Model publication status: AccessStatus.SUCCESS
2018-05-13 11:42:36,356 - INFO - COM8.ConfigurationClient: Publication status for model 00590001 at element 18 to {'address': 0010, 'index': 0, 'ttl': 1, 'period': 0, 'retransmit': {'count': 0, 'interval_steps': 0, 'interval': 50}, 'credentials': <FriendshipCredentials.DISABLED: 0>}
2018-05-13 11:42:36,361 - DEBUG - COM8: Message Opcode bytearray(b'\x80\x19'), Data bytearray(b'\x00\x12\x00\x10\x00\x00\x00\x01\x00\x00Y\x00\x01\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 11:43:54,033 - DEBUG - COM8.ConfigurationClient: Sending opcode: 03, data: 100001c0000001000059000000
2018-05-13 11:43:54,033 - DEBUG - COM8: TX: 18ab08000100000008000003100001c0000001000059000000
2018-05-13 11:43:54,037 - DEBUG - COM8: RX: 0384ab00
2018-05-13 11:43:54,038 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 11:43:54,038 - INFO - COM8: Success
2018-05-13 11:43:54,132 - DEBUG - COM8: RX: 24d0100001000800000004013ee062b88de2eb1000801900100001c0000001000059000000
2018-05-13 11:43:54,132 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 4, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -21, 'actual_length': 16, 'data': bytearray(b'\x80\x19\x00\x10\x00\x01\xc0\x00\x00\x01\x00\x00Y\x00\x00\x00')}}
2018-05-13 11:43:54,132 - INFO - COM8.ConfigurationClient: Model publication status: AccessStatus.SUCCESS
2018-05-13 11:43:54,139 - INFO - COM8.ConfigurationClient: Publication status for model 00590000 at element 16 to {'address': c001, 'index': 0, 'ttl': 1, 'period': 0, 'retransmit': {'count': 0, 'interval_steps': 0, 'interval': 50}, 'credentials': <FriendshipCredentials.DISABLED: 0>}
2018-05-13 11:43:54,141 - DEBUG - COM8: Message Opcode bytearray(b'\x80\x19'), Data bytearray(b'\x00\x10\x00\x01\xc0\x00\x00\x01\x00\x00Y\x00\x00\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:10:38,866 - DEBUG - COM8.ConfigurationClient: Sending opcode: 801b, data: 120001c059000100
2018-05-13 12:10:38,867 - DEBUG - COM8: TX: 14ab090001000100080000801b120001c059000100
2018-05-13 12:10:38,871 - DEBUG - COM8: RX: 0384ab00
2018-05-13 12:10:38,871 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 12:10:38,871 - INFO - COM8: Success
2018-05-13 12:10:38,919 - DEBUG - COM8: RX: 1fd011000100090000001e016ac110b522d1da0b00801f00120001c059000100
2018-05-13 12:10:38,920 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 17, 'dst': 1, 'appkey_handle': 9, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'j\xc1\x10\xb5"\xd1'), 'rssi': -38, 'actual_length': 11, 'data': bytearray(b'\x80\x1f\x00\x12\x00\x01\xc0Y\x00\x01\x00')}}
2018-05-13 12:10:38,920 - INFO - COM8.ConfigurationClient: Model subscription status: AccessStatus.SUCCESS
2018-05-13 12:10:38,928 - INFO - COM8.ConfigurationClient: Added subscription 'c001' to model 00590001 at element 0012
2018-05-13 12:10:38,928 - DEBUG - COM8: Message Opcode bytearray(b'\x80\x1f'), Data bytearray(b'\x00\x12\x00\x01\xc0Y\x00\x01\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:10:53,183 - DEBUG - COM8.SimpleOnOffClient: Sending opcode: c10059, data: 0101
2018-05-13 12:10:53,184 - DEBUG - COM8: TX: 0fab000001000000080000c100590101
2018-05-13 12:10:53,187 - DEBUG - COM8: RX: 0384ab00
2018-05-13 12:10:53,187 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 12:10:53,187 - INFO - COM8: Success
2018-05-13 12:10:53,233 - DEBUG - COM8: RX: 18d0100001000000000001013ee062b88de2eb0400c4005901
2018-05-13 12:10:53,233 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 0, 'subnet_handle': 0, 'ttl': 1, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -21, 'actual_length': 4, 'data': bytearray(b'\xc4\x00Y\x01')}}
2018-05-13 12:10:53,233 - DEBUG - COM8: Message Opcode bytearray(b'\xc4\x00Y'), Data bytearray(b'\x01') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:10:53,233 - INFO - COM8.SimpleOnOffClient: Present value is on
2018-05-13 12:11:04,398 - DEBUG - COM8.SimpleOnOffClient: Sending opcode: c10059, data: 0002
2018-05-13 12:11:04,398 - DEBUG - COM8: TX: 0fab000001000000080000c100590002
2018-05-13 12:11:04,402 - DEBUG - COM8: RX: 0384ab00
2018-05-13 12:11:04,402 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 12:11:04,402 - INFO - COM8: Success
2018-05-13 12:11:04,448 - DEBUG - COM8: RX: 18d0100001000000000001013ee062b88de2eb0400c4005900
2018-05-13 12:11:04,448 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 0, 'subnet_handle': 0, 'ttl': 1, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -21, 'actual_length': 4, 'data': bytearray(b'\xc4\x00Y\x00')}}
2018-05-13 12:11:04,450 - DEBUG - COM8: Message Opcode bytearray(b'\xc4\x00Y'), Data bytearray(b'\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:11:04,450 - INFO - COM8.SimpleOnOffClient: Present value is off
2018-05-13 12:11:20,876 - DEBUG - COM8.SimpleOnOffClient: Sending opcode: c10059, data: 0103
2018-05-13 12:11:20,876 - DEBUG - COM8: TX: 0fab000001000000080000c100590103
2018-05-13 12:11:20,880 - DEBUG - COM8: RX: 0384ab00
2018-05-13 12:11:20,880 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 12:11:20,880 - INFO - COM8: Success
2018-05-13 12:11:20,895 - DEBUG - COM8: RX: 18d0100001000000000001013ee062b88de2ea0400c4005901
2018-05-13 12:11:20,895 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 0, 'subnet_handle': 0, 'ttl': 1, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -22, 'actual_length': 4, 'data': bytearray(b'\xc4\x00Y\x01')}}
2018-05-13 12:11:20,895 - DEBUG - COM8: Message Opcode bytearray(b'\xc4\x00Y'), Data bytearray(b'\x01') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:11:20,896 - INFO - COM8.SimpleOnOffClient: Present value is on
2018-05-13 12:11:25,007 - DEBUG - COM8.SimpleOnOffClient: Sending opcode: c10059, data: 0004
2018-05-13 12:11:25,008 - DEBUG - COM8: TX: 0fab000001000000080000c100590004
2018-05-13 12:11:25,010 - DEBUG - COM8: RX: 0384ab00
2018-05-13 12:11:25,011 - DEBUG - COM8: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'')}}
2018-05-13 12:11:25,011 - INFO - COM8: Success
2018-05-13 12:11:25,060 - DEBUG - COM8: RX: 18d0100001000000000001013ee062b88de2eb0400c4005900
2018-05-13 12:11:25,060 - DEBUG - COM8: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 0, 'subnet_handle': 0, 'ttl': 1, 'adv_addr_type': 1, 'adv_addr': bytearray(b'>\xe0b\xb8\x8d\xe2'), 'rssi': -21, 'actual_length': 4, 'data': bytearray(b'\xc4\x00Y\x00')}}
2018-05-13 12:11:25,060 - DEBUG - COM8: Message Opcode bytearray(b'\xc4\x00Y'), Data bytearray(b'\x00') unknown for model <mesh.access.Access object at 0x0000016726BB5A20>.
2018-05-13 12:11:25,060 - INFO - COM8.SimpleOnOffClient: Present value is off
2018-05-13 12:11:33,268 - DEBUG - COM8: exited read event