Receiving data in from Generic On Off Client through pyACI

Hi, 

I am trying to get event messages on the terminal from a Generic On Off (GOO) Client node.

I have the provisioned the mesh using the pyAci through another board running the serial example. I followed the steps in the serial examples, which work as expected. I configured the device and models with application keys and group address, as well as setting the publication address. (In the code below it is only set on the first model, but tried both and also setting subscription address in previous attempts). I have also tried to create a virtual GOO Server to listen to events. I guess I am expecting some RX messages to pop up in the shell when the board buttons are pressed, however I could be on completely the wrong track.

How can I get data in from the mesh devices?

Many thanks in advance, 

Tim

Environment:
OSX
nrf5SDK for Mesh v310
2 x NRF52832 BK boards one with serial example and second with light switch client example

interactive_pyaci shell:

 
In [1]: db = MeshDB("database/example_database.json")

In [2]: p = Provisioner(device, db)

2019-06-12 23:11:36,356 - DEBUG - tty.usbmodem0006822145041: TX: 616954ec8b19f34449178c4e4b22c155379fc89697ca63b07115b49cbbe8b6e654e0d421ab792c5782f572c69491f13463dd8d67a04b9ab8ffa04411967f0b48795441fa89a0dced7390b74ecb08c300bdca5e63a17745a67d722ecb49380a838c8d
In [3]: 2019-06-12 23:11:36,370 - DEBUG - tty.usbmodem0006822145041: RX: 03845384
2019-06-12 23:11:36,370 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 83, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,370 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,371 - DEBUG - tty.usbmodem0006822145041: TX: 059f01000100
2019-06-12 23:11:36,371 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,371 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,372 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,372 - DEBUG - tty.usbmodem0006822145041: TX: 1392000018eed9c2a56add85049ffc3c59ad0e12
2019-06-12 23:11:36,372 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,372 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,373 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,373 - DEBUG - tty.usbmodem0006822145041: TX: 1597000000004f68ad85d9f48ac8589df665b6b49b8a
2019-06-12 23:11:36,374 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,374 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,375 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,375 - DEBUG - tty.usbmodem0006822145041: TX: 1597010000002aa2a6ded5a0798ceab5787ca3ae39fc
2019-06-12 23:11:36,376 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,376 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,376 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,376 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,384 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,384 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,384 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,384 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,385 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,385 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,385 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,385 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,385 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,385 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,386 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,386 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,386 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,386 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,386 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,386 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,387 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,387 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,387 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,388 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,389 - DEBUG - tty.usbmodem0006822145041: RX: 03840084
2019-06-12 23:11:36,389 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 0, 'status': 132, 'data': bytearray(b'')}}
2019-06-12 23:11:36,390 - ERROR - tty.usbmodem0006822145041: None: ERROR_INVALID_LENGTH
2019-06-12 23:11:36,390 - DEBUG - tty.usbmodem0006822145041: RX: 03849f00
2019-06-12 23:11:36,390 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 159, 'status': 0, 'data': bytearray(b'')}}
2019-06-12 23:11:36,391 - INFO - tty.usbmodem0006822145041: Success
2019-06-12 23:11:36,391 - DEBUG - tty.usbmodem0006822145041: RX: 058492000000
2019-06-12 23:11:36,392 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 146, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2019-06-12 23:11:36,393 - INFO - tty.usbmodem0006822145041: SubnetAdd: {'subnet_handle': 0}
2019-06-12 23:11:36,395 - DEBUG - tty.usbmodem0006822145041: RX: 058497000000
2019-06-12 23:11:36,395 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2019-06-12 23:11:36,397 - INFO - tty.usbmodem0006822145041: AppkeyAdd: {'appkey_handle': 0}
2019-06-12 23:11:36,398 - DEBUG - tty.usbmodem0006822145041: RX: 058497000100
2019-06-12 23:11:36,398 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 151, 'status': 0, 'data': bytearray(b'\x01\x00')}}
2019-06-12 23:11:36,399 - INFO - tty.usbmodem0006822145041: AppkeyAdd: {'appkey_handle': 1}
In [3]:

In [3]:

In [3]: p.scan_start()

2019-06-12 23:11:46,071 - DEBUG - tty.usbmodem0006822145041: TX: 0161
In [4]: 2019-06-12 23:11:46,076 - DEBUG - tty.usbmodem0006822145041: RX: 03846100
2019-06-12 23:11:46,076 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 97, 'status': 0, 'data': bytearray(b'')}}
2019-06-12 23:11:46,077 - INFO - tty.usbmodem0006822145041: Success
2019-06-12 23:11:46,092 - DEBUG - tty.usbmodem0006822145041: RX: 1ac09db77a0526b8734988639509c242d107e60001c8639509c2c2
2019-06-12 23:11:46,092 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x9d\xb7z\x05&\xb8sI\x88c\x95\t\xc2B\xd1\x07'), 'rssi': -26, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2')}}
2019-06-12 23:11:46,093 - INFO - tty.usbmodem0006822145041: Received UUID 9db77a0526b8734988639509c242d107 with RSSI: -26 dB
2019-06-12 23:11:48,101 - DEBUG - tty.usbmodem0006822145041: RX: 1ac09db77a0526b8734988639509c242d107e70001c8639509c2c2
2019-06-12 23:11:48,101 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x9d\xb7z\x05&\xb8sI\x88c\x95\t\xc2B\xd1\x07'), 'rssi': -25, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2')}}
In [4]:

In [4]:

In [4]:

In [4]: p.scan_stop()2019-06-12 23:11:50,120 - DEBUG - tty.usbmodem0006822145041: RX: 1ac09db77a0526b8734988639509c242d107e60001c8639509c2c2
2019-06-12 23:11:50,120 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvUnprovisionedReceived, data: {'uuid': bytearray(b'\x9d\xb7z\x05&\xb8sI\x88c\x95\t\xc2B\xd1\x07'), 'rssi': -26, 'gatt_supported': 0, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2')}}
In [4]: p.scan_stop()

2019-06-12 23:11:50,144 - DEBUG - tty.usbmodem0006822145041: TX: 0162
2019-06-12 23:11:50,158 - DEBUG - tty.usbmodem0006822145041: RX: 03846200
2019-06-12 23:11:50,162 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 98, 'status': 0, 'data': bytearray(b'')}}
2019-06-12 23:11:50,166 - INFO - tty.usbmodem0006822145041: Success
In [5]:

In [5]:

In [5]: p.provision(name="Client")

In [6]: 2019-06-12 23:11:55,875 - DEBUG - tty.usbmodem0006822145041: TX: 2d63009db77a0526b8734988639509c242d10718eed9c2a56add85049ffc3c59ad0e120000000000001000000000
2019-06-12 23:11:55,880 - DEBUG - tty.usbmodem0006822145041: RX: 0484630000
2019-06-12 23:11:55,881 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 99, 'status': 0, 'data': bytearray(b'\x00')}}
2019-06-12 23:11:55,881 - INFO - tty.usbmodem0006822145041: Provision: {'context': 0}
2019-06-12 23:11:55,909 - DEBUG - tty.usbmodem0006822145041: RX: 02c100
2019-06-12 23:11:55,911 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvLinkEstablished, data: {'context_id': 0}}
2019-06-12 23:11:55,913 - INFO - tty.usbmodem0006822145041: Link established
2019-06-12 23:11:55,977 - DEBUG - tty.usbmodem0006822145041: RX: 0bc300030001000000000000
2019-06-12 23:11:55,978 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvCapsReceived, data: {'context_id': 0, 'num_elements': 3, 'public_key_type': 0, 'static_oob_types': 1, 'output_oob_size': 0, 'output_oob_actions': 0, 'input_oob_size': 0, 'input_oob_actions': 0}}
2019-06-12 23:11:55,978 - INFO - tty.usbmodem0006822145041: Received capabilities
2019-06-12 23:11:55,978 - INFO - tty.usbmodem0006822145041: Number of elements: 3
2019-06-12 23:11:55,979 - DEBUG - tty.usbmodem0006822145041: TX: 056600000000
2019-06-12 23:11:55,980 - DEBUG - tty.usbmodem0006822145041: RX: 0484660000
2019-06-12 23:11:55,981 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 102, 'status': 0, 'data': bytearray(b'\x00')}}
2019-06-12 23:11:55,981 - INFO - tty.usbmodem0006822145041: OobUse: {'context': 0}
2019-06-12 23:11:56,172 - DEBUG - tty.usbmodem0006822145041: RX: 62c7006d3c4542b959b5b0635dee1e2dd766df39f84181040c108e479a5757a08250e4a195af93cd2a699b35f44adb3c3f02ec4f22cabb4e720666915f8e93d7b5123a88fd41dd23969ec32f6ea5d1d70563cd3fd8c33bbea526a1b98d3d27dc270c2b
2019-06-12 23:11:56,173 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvEcdhRequest, data: {'context_id': 0, 'peer_public': bytearray(b'm<EB\xb9Y\xb5\xb0c]\xee\x1e-\xd7f\xdf9\xf8A\x81\x04\x0c\x10\x8eG\x9aWW\xa0\x82P\xe4\xa1\x95\xaf\x93\xcd*i\x9b5\xf4J\xdb<?\x02\xecO"\xca\xbbNr\x06f\x91_\x8e\x93\xd7\xb5\x12:'), 'node_private': bytearray(b"\x88\xfdA\xdd#\x96\x9e\xc3/n\xa5\xd1\xd7\x05c\xcd?\xd8\xc3;\xbe\xa5&\xa1\xb9\x8d=\'\xdc\'\x0c+")}}
2019-06-12 23:11:56,173 - INFO - tty.usbmodem0006822145041: ECDH request received
2019-06-12 23:11:56,174 - DEBUG - tty.usbmodem0006822145041: TX: 226800e3b0ad5884916c4fe1bfa377f6382cc0fb57580fb1a6482afe32bb8d86029a10
2019-06-12 23:11:56,179 - DEBUG - tty.usbmodem0006822145041: RX: 0484680000
2019-06-12 23:11:56,180 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 104, 'status': 0, 'data': bytearray(b'\x00')}}
2019-06-12 23:11:56,180 - INFO - tty.usbmodem0006822145041: EcdhSecret: {'context': 0}
2019-06-12 23:11:56,511 - DEBUG - tty.usbmodem0006822145041: RX: 2cc500000000000000100000008e134fdaa6f80cf523af9384a653e95d18eed9c2a56add85049ffc3c59ad0e12
2019-06-12 23:11:56,512 - DEBUG - tty.usbmodem0006822145041: 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'\x8e\x13O\xda\xa6\xf8\x0c\xf5#\xaf\x93\x84\xa6S\xe9]'), 'net_key': bytearray(b'\x18\xee\xd9\xc2\xa5j\xdd\x85\x04\x9f\xfc<Y\xad\x0e\x12')}}
2019-06-12 23:11:56,512 - INFO - tty.usbmodem0006822145041: Provisioning complete
2019-06-12 23:11:56,512 - INFO - tty.usbmodem0006822145041: 	Address(es): 0x10-0x12
2019-06-12 23:11:56,512 - INFO - tty.usbmodem0006822145041: 	Device key: 8e134fdaa6f80cf523af9384a653e95d
2019-06-12 23:11:56,512 - INFO - tty.usbmodem0006822145041: 	Network key: 18eed9c2a56add85049ffc3c59ad0e12
2019-06-12 23:11:56,512 - INFO - tty.usbmodem0006822145041: Adding device key to subnet 0
2019-06-12 23:11:56,513 - INFO - tty.usbmodem0006822145041: Adding publication address of root element
2019-06-12 23:11:56,513 - DEBUG - tty.usbmodem0006822145041: TX: 159c100000008e134fdaa6f80cf523af9384a653e95d
2019-06-12 23:11:56,515 - DEBUG - tty.usbmodem0006822145041: TX: 03a41000
2019-06-12 23:11:56,517 - DEBUG - tty.usbmodem0006822145041: RX: 05849c000800
2019-06-12 23:11:56,518 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 156, 'status': 0, 'data': bytearray(b'\x08\x00')}}
2019-06-12 23:11:56,518 - INFO - tty.usbmodem0006822145041: DevkeyAdd: {'devkey_handle': 8}
2019-06-12 23:11:56,518 - DEBUG - tty.usbmodem0006822145041: RX: 0584a4000000
2019-06-12 23:11:56,518 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 164, 'status': 0, 'data': bytearray(b'\x00\x00')}}
2019-06-12 23:11:56,518 - INFO - tty.usbmodem0006822145041: AddrPublicationAdd: {'address_handle': 0}
2019-06-12 23:11:56,626 - DEBUG - tty.usbmodem0006822145041: RX: 03c20000
2019-06-12 23:11:56,627 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: ProvLinkClosed, data: {'context_id': 0, 'close_reason': 0}}
2019-06-12 23:11:56,627 - INFO - tty.usbmodem0006822145041: Provisioning link closed
In [6]:

In [6]:

In [6]: cc = ConfigurationClient(db)

In [7]:

In [7]: device.model_add(cc)

In [8]: cc.publish_set(8, 0)

In [9]: cc.composition_data_get()
2019-06-12 23:12:21,001 - DEBUG - tty.usbmodem0006822145041.ConfigurationClient: Sending opcode: 8008, data: 00

2019-06-12 23:12:21,002 - DEBUG - tty.usbmodem0006822145041: TX: 0eab08000100000008000000800800
In [10]: 2019-06-12 23:12:21,007 - DEBUG - tty.usbmodem0006822145041: RX: 0784ab0001000000
2019-06-12 23:12:21,010 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'\x01\x00\x00\x00')}}
2019-06-12 23:12:21,011 - INFO - tty.usbmodem0006822145041: PacketSend: {'token': 1}
2019-06-12 23:12:21,011 - DEBUG - tty.usbmodem0006822145041: RX: 05d201000000
2019-06-12 23:12:21,012 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshTxComplete, data: {'token': 1}}
2019-06-12 23:12:21,012 - INFO - tty.usbmodem0006822145041: {event: MeshTxComplete, data: {'token': 1}}
2019-06-12 23:12:21,085 - DEBUG - tty.usbmodem0006822145041: RX: 34d010000100080000001e01c8639509c2c2e620000200590000000000280003000000020000000200000001000110000001000110
2019-06-12 23:12:21,085 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2'), 'rssi': -26, 'actual_length': 32, 'data': bytearray(b'\x02\x00Y\x00\x00\x00\x00\x00(\x00\x03\x00\x00\x00\x02\x00\x00\x00\x02\x00\x00\x00\x01\x00\x01\x10\x00\x00\x01\x00\x01\x10')}}
2019-06-12 23:12:21,087 - INFO - tty.usbmodem0006822145041.ConfigurationClient: Received composition data (page 0x00): {
  "cid": "0059",
  "pid": "0000",
  "vid": "0000",
  "crpl": 40,
  "features": {
    "relay": 0,
    "proxy": 0,
    "friend": 2,
    "low_power": 2
  },
  "elements": [
    {
      "index": 0,
      "location": "0000",
      "models": [
        {
          "modelId": "0000"
        },
        {
          "modelId": "0002"
        }
      ]
    },
    {
      "index": 1,
      "location": "0000",
      "models": [
        {
          "modelId": "1001"
        }
      ]
    },
    {
      "index": 2,
      "location": "0000",
      "models": [
        {
          "modelId": "1001"
        }
      ]
    }
  ]
}
In [10]:

In [10]:

In [10]: cc.appkey_add(0)
2019-06-12 23:12:26,311 - DEBUG - tty.usbmodem0006822145041.ConfigurationClient: Sending opcode: 00, data: 0000004f68ad85d9f48ac8589df665b6b49b8a

In [11]: 2019-06-12 23:12:26,317 - DEBUG - tty.usbmodem0006822145041: TX: 1fab08000100000008000000000000004f68ad85d9f48ac8589df665b6b49b8a
2019-06-12 23:12:26,323 - DEBUG - tty.usbmodem0006822145041: RX: 0784ab0002000000
2019-06-12 23:12:26,323 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'\x02\x00\x00\x00')}}
2019-06-12 23:12:26,323 - INFO - tty.usbmodem0006822145041: PacketSend: {'token': 2}
2019-06-12 23:12:26,375 - DEBUG - tty.usbmodem0006822145041: RX: 05d202000000
2019-06-12 23:12:26,375 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshTxComplete, data: {'token': 2}}
2019-06-12 23:12:26,375 - INFO - tty.usbmodem0006822145041: {event: MeshTxComplete, data: {'token': 2}}
2019-06-12 23:12:26,406 - DEBUG - tty.usbmodem0006822145041: RX: 1ad010000100080000001e01c8639509c2c2e60600800300000000
2019-06-12 23:12:26,407 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2'), 'rssi': -26, 'actual_length': 6, 'data': bytearray(b'\x80\x03\x00\x00\x00\x00')}}
2019-06-12 23:12:26,408 - INFO - tty.usbmodem0006822145041.ConfigurationClient: Appkey status: AccessStatus.SUCCESS
2019-06-12 23:12:26,411 - INFO - tty.usbmodem0006822145041.ConfigurationClient: Appkey add 0 succeded for subnet 0 at node 0010
In [11]:

In [11]: d[0].send(cmd.AddrPublicationAdd(db.groups[0].address))

2019-06-12 23:12:36,737 - DEBUG - tty.usbmodem0006822145041: TX: 03a401c0
In [12]: 2019-06-12 23:12:36,743 - DEBUG - tty.usbmodem0006822145041: RX: 0584a4000100
2019-06-12 23:12:36,743 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 164, 'status': 0, 'data': bytearray(b'\x01\x00')}}
2019-06-12 23:12:36,743 - INFO - tty.usbmodem0006822145041: AddrPublicationAdd: {'address_handle': 1}
In [12]:

In [12]: cc.model_publication_set(db.nodes[0].unicast_address + 1, mt.ModelId(0x1001), mt.Publish(db.groups[0].address, index=0, ttl=1))
2019-06-12 23:12:47,640 - DEBUG - tty.usbmodem0006822145041.ConfigurationClient: Sending opcode: 03, data: 110001c000000100000110

2019-06-12 23:12:47,642 - DEBUG - tty.usbmodem0006822145041: TX: 17ab0800010000000800000003110001c000000100000110
In [13]: 2019-06-12 23:12:47,648 - DEBUG - tty.usbmodem0006822145041: RX: 0784ab0003000000
2019-06-12 23:12:47,650 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: CmdRsp, data: {'opcode': 171, 'status': 0, 'data': bytearray(b'\x03\x00\x00\x00')}}
2019-06-12 23:12:47,651 - INFO - tty.usbmodem0006822145041: PacketSend: {'token': 3}
2019-06-12 23:12:47,686 - DEBUG - tty.usbmodem0006822145041: RX: 05d203000000
2019-06-12 23:12:47,688 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshTxComplete, data: {'token': 3}}
2019-06-12 23:12:47,689 - INFO - tty.usbmodem0006822145041: {event: MeshTxComplete, data: {'token': 3}}
2019-06-12 23:12:47,735 - DEBUG - tty.usbmodem0006822145041: RX: 22d010000100080000001e01c8639509c2c2e70e00801900110001c000000100000110
2019-06-12 23:12:47,736 - DEBUG - tty.usbmodem0006822145041: parsed_packet {event: MeshMessageReceivedUnicast, data: {'src': 16, 'dst': 1, 'appkey_handle': 8, 'subnet_handle': 0, 'ttl': 30, 'adv_addr_type': 1, 'adv_addr': bytearray(b'\xc8c\x95\t\xc2\xc2'), 'rssi': -25, 'actual_length': 14, 'data': bytearray(b'\x80\x19\x00\x11\x00\x01\xc0\x00\x00\x01\x00\x00\x01\x10')}}
2019-06-12 23:12:47,736 - INFO - tty.usbmodem0006822145041.ConfigurationClient: Model publication status: AccessStatus.SUCCESS
2019-06-12 23:12:47,738 - INFO - tty.usbmodem0006822145041.ConfigurationClient: Publication status for model 1001 at element 17 to {'address': c001, 'index': 0, 'ttl': 1, 'period': 0, 'retransmit': {'count': 0, 'interval_steps': 0, 'interval': 50}, 'credentials': <FriendshipCredentials.DISABLED: 0>}
In [13]:

In [13]:

In [13]: device.event_filter_disable()

In [14]: gs = GenericOnOffServer()
    ...: device.model_add(gs)
    ...: gs.publish_set(0, 1)

In [15]:

In [15]:

In [15]:

Segger Debug Terminal:

<t:          0>, main.c,  318, ----- BLE Mesh Light Switch Client Demo -----
<t:      17819>, main.c,  289, Initializing and adding models
<t:      22666>, mesh_app_utils.c,   65, Device UUID (raw): 9DB77A0526B8734988639509C242D107
<t:      22669>, mesh_app_utils.c,   70, Device UUID : 057AB79D-B826-4973-8863-9509C242D107
<t:    1618972>, main.c,  112, Successfully provisioned
<t:    1618977>, main.c,  123, Node Address: 0x0010 
<t:    2284450>, config_server.c,  623, dsm_appkey_add(appkey_handle:0 appkey_index:0)
<t:    3583957>, proxy.c,  638, Adv timeout
<t:    3971888>, main.c,  200, Button 0 pressed
<t:    3971890>, main.c,  227, Sending msg: ONOFF SET 1
<t:    4001163>, main.c,  200, Button 0 pressed
<t:    4001165>, main.c,  227, Sending msg: ONOFF SET 1
<t:    4001168>, main.c,  156, Acknowledged transfer cancelled.
<t:    4046407>, main.c,  200, Button 1 pressed
<t:    4046409>, main.c,  227, Sending msg: ONOFF SET 0
<t:    4046412>, main.c,  156, Acknowledged transfer cancelled.
<t:    4374102>, main.c,  152, Acknowledged transfer timeout.
<t:    4807435>, main.c,  200, Button 2 pressed
<t:    4807438>, main.c,  227, Sending msg: ONOFF SET 1
<t:    4807440>, main.c,  269, Publication not configured for client 2
<t:    4832173>, main.c,  200, Button 3 pressed
<t:    4832175>, main.c,  227, Sending msg: ONOFF SET 0
<t:    4832178>, main.c,  269, Publication not configured for client 3

GenericOnOffServer in generic_on_off.py

class GenericOnOffServer(Model):
    GENERIC_ON_OFF_SET = Opcode(0x8202, None, "Generic OnOff Set")
    GENERIC_ON_OFF_SET_UNACKNOWLEDGED = Opcode(0x8203, None, "Generic OnOff Set Unacknowledged")
    GENERIC_ON_OFF_GET = Opcode(0x8201, None, "Generic OnOff Get")
    GENERIC_ON_OFF_STATUS = Opcode(0x8204, None, "Generic OnOff Status")
    
    def __init__(self):
        self.opcodes = [
            (self.GENERIC_ON_OFF_SET, self.__generic_on_off_server_event_handler),
            (self.GENERIC_ON_OFF_SET_UNACKNOWLEDGED, self.__generic_on_off_server_event_handler),
            (self.GENERIC_ON_OFF_GET, self.__generic_on_off_server_event_handler),
            (self.GENERIC_ON_OFF_STATUS, self.__generic_on_off_server_event_handler)]
        self.__tid = 0
        super(GenericOnOffServer, self).__init__(self.opcodes)
    
    @property
    def _tid(self):
        tid = self.__tid
        self.__tid += 1
        if self.__tid >= 255:
            self.__tid = 0
        return tid

    def __generic_on_off_server_event_handler(self, opcode, message):
        print("Server Event {} {}".format(opcode, message))
        self.logger.debug("Server Event {} {}".format(opcode, message))

mesh database

{
  "$schema": "",
  "appKeys": [
    {
      "boundNetKey": 0,
      "index": 0,
      "key": "4f68ad85d9f48ac8589df665b6b49b8a",
      "name": "lights"
    },
    {
      "boundNetKey": 0,
      "index": 1,
      "key": "2aa2a6ded5a0798ceab5787ca3ae39fc",
      "name": "locks"
    }
  ],
  "groups": [
    {
      "address": 49153,
      "name": "Room 1",
      "parentAddress": 0
    },
    {
      "address": 49154,
      "name": "Room 2",
      "parentAddress": 0
    }
  ],
  "ivIndex": 0,
  "ivUpdate": 0,
  "meshName": "BT Mesh",
  "meshUUID": "01020304050607080102030405060708",
  "netKeys": [
    {
      "index": 0,
      "key": "18eed9c2a56add85049ffc3c59ad0e12",
      "minSecurity": "low",
      "name": "root",
      "phase": 0
    }
  ],
  "nodes": [
    {
      "UUID": "9db77a0526b8734988639509c242d107",
      "appKeys": [
        0
      ],
      "cid": "0059",
      "configComplete": false,
      "crpl": 40,
      "deviceKey": "8e134fdaa6f80cf523af9384a653e95d",
      "elements": [
        {
          "index": 0,
          "location": "0000",
          "models": [
            {
              "modelId": "0000"
            },
            {
              "modelId": "0002"
            }
          ]
        },
        {
          "index": 1,
          "location": "0000",
          "models": [
            {
              "modelId": "1001",
              "publish": {
                "address": 49153,
                "credentials": 0,
                "index": 0,
                "period": 0,
                "retransmit": {
                  "count": 0,
                  "interval": 50
                },
                "ttl": 1
              }
            }
          ]
        },
        {
          "index": 2,
          "location": "0000",
          "models": [
            {
              "modelId": "1001"
            }
          ]
        }
      ],
      "features": {
        "friend": 2,
        "lowPower": 2,
        "proxy": 0,
        "relay": 0
      },
      "name": "Client",
      "netKeys": [
        0
      ],
      "pid": "0000",
      "security": "low",
      "unicastAddress": 16,
      "vid": "0000"
    }
  ],
  "provisioners": [
    {
      "UUID": "00000000000000000000000000000000",
      "allocatedGroupRange": [
        {
          "highAddress": 65279,
          "lowAddress": 49152
        }
      ],
      "allocatedUnicastRange": [
        {
          "highAddress": 32767,
          "lowAddress": 16
        }
      ],
      "name": "BT Mesh Provisioner"
    }
  ],
  "timestamp": "2019-06-12 23:12:47.736705"