Interactive PyACI : Group Publish/subscribe with server and client not working properly ?

[ValentinL]

Hello,

I am working with the Interactive PyACI (nRF_SDK_for_Mesh 4.0.0 with boards nRF52832). I followed the tutorial "demo_configuration" present in the doc folder.
Every works fine, I can scan, provision, bind servers and clients.
Now I want to have a set up where a server send "notification" and other boards, which are client I guess, will get the information = state change (with a genericOnOff).
So I think that correspond to the last point of the tutorial : #### Publishing and subscribing @anchor pyaci_demo_configuration_starting_configuration_5_publishing.
I did as said in the tutorial, It looks like server and client are well configured because I get all correct return message and the the Json file looks correct (see attach).
But when I set the server with gc.set(True), the led on the server board turn on but nothing happen on the client board.
Yet I suppose the led on the client board must turn on since in the tutorial it is written : "You should now be able to use the Generic OnOff client to change the state of the server and observe
that the client also changes its state accordingly".
Is it normal that nothing happen on the client board ? How can we make a proper publishing/subscribing to a group please ? :)

Wainting for an answer, Thank you very much !

Fullscreen example_database (copy).txt Download

{
  "$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": "1578bc42364ea4409a9b364acb9bf093",
      "cid": "0059",
      "configComplete": false,
      "crpl": 40,
      "deviceKey": "eb9f7f71eafde62a9998e37ce8b80005",
      "elements": [
        {
          "index": 0,
          "location": "0000",
          "models": [
            {
              "modelId": "0000"
            },
            {
              "modelId": "0002"
            }
          ]
        },
        {
          "index": 1,
          "location": "0000",
          "models": [
            {
              "bind": [
                0
              ],
              "modelId": "1001",
              "subscribe": [
                49153
              ]
            }
          ]
        },
        {
          "index": 2,
          "location": "0000",
          "models": [
            {
              "modelId": "1001"
            }
          ]
        }
      ],
      "features": {
        "friend": 2,
        "lowPower": 2,
        "proxy": 0,
        "relay": 0
      },
      "netKeys": [
        0
      ],
      "pid": "0000",
      "security": "low",
      "unicastAddress": 16,
      "vid": "0000"
    },
    {
      "UUID": "eb1be75149de7d4ea9f4e67a497feaaf",
      "cid": "0059",
      "configComplete": false,
      "crpl": 40,
      "deviceKey": "4a811697dfeed1c4a7652e5b49f26f91",
      "elements": [
        {
          "index": 0,
          "location": "0000",
          "models": [
            {
              "modelId": "0000"
            },
            {
              "modelId": "0002"
            },
            {
              "bind": [
                0
              ],
              "modelId": "1000",
              "publish": {
                "address": 49153,
                "credentials": 0,
                "index": 0,
                "period": 0,
                "retransmit": {
                  "count": 0,
                  "interval": 50
                },
                "ttl": 1
              }
            }
          ]
        }
      ],
      "features": {
        "friend": 2,
        "lowPower": 2,
        "proxy": 0,
        "relay": 0
      },
      "netKeys": [
        0
      ],
      "pid": "0000",
      "security": "low",
      "unicastAddress": 19,
      "vid": "0000"
    }
  ],
  "provisioners": [
    {
      "UUID": "00000000000000000000000000000000",
      "allocatedGroupRange": [
        {
          "highAddress": 65279,
          "lowAddress": 49152
        }
      ],
      "allocatedUnicastRange": [
        {
          "highAddress": 32767,
          "lowAddress": 16
        }
      ],
      "name": "BT Mesh Provisioner"
    }
  ],
  "timestamp": "2020-06-04 14:21:52.297678"
}

[Hung Bui]

Hi ValentinL, 

It's would be nice to get some more logging in formation on the client side and the server side. 
We would need to know at which step it failed. 

Please note that the client only listen to the status replied directly to it, not the status change broadcast by the server (AFAIK) . So if you send the command to change the LED state from the client (by click the button on the client) you should see LED get updated on both the client and the server. 

[ValentinL]

Hi,

I'll provide you some logging information monday. But when you say "Please note that the client only listen to the status replied directly to it, not the status change broadcast by the server (AFAIK)", do you mean that if It is normal in my set up that there is no led change on the client ?
I recall my set up : I have my provisionner which change state of the server (with gc.set()) and this server publish to a group. The client subscribe to this group. What should happen on the client when I do gc.set(True) ?
Now I the led turn on on the server board (logic) but nothing happen on the client board.

Yes I tried with a client by clicking on the button, the server also update. But is that note possible the other way around ? 
The server publish and the client state change by subscribing ?

I send you the log on monday,

Thank you

[ValentinL]

Here is the command I do and the log I receive (I custom some log command and log but you should easily understand)

1) db = MeshDB(pathlib)
2) p = Provisioner(device, db)
None: ERROR_INVALID_LENGTH
None: ERROR_INVALID_LENGTH
None: ERROR_INVALID_LENGTH
None: ERROR_INVALID_LENGTH
None: ERROR_INVALID_LENGTH
Success
SubnetAdd: {'subnet_handle': 0}
AppkeyAdd: {'appkey_handle': 0}
AppkeyAdd: {'appkey_handle': 1}

3) p.scan_start()
StartScan
Success
Received UUID 1578bc42364ea4409a9b364acb9bf093 with RSSI: -43 dB
Received UUID eb1be75149de7d4ea9f4e67a497feaaf with RSSI: -29 dB

4) p.scan_stop()
5) p.provision (I do a loop on every device I scan as unprov, here I have 2) so I get this log :
unprov liste = [bytearray(b'\x15x\xbcB6N\xa4@\x9a\x9b6J\xcb\x9b\xf0\x93'), bytearray(b'\xeb\x1b\xe7QI\xde}N\xa9\xf4\xe6zI\x7f\xea\xaf')]
prov_list ... = [bytearray(b'\x15x\xbcB6N\xa4@\x9a\x9b6J\xcb\x9b\xf0\x93')]
unprov liste = [bytearray(b'\xeb\x1b\xe7QI\xde}N\xa9\xf4\xe6zI\x7f\xea\xaf')]
Provision: {'context': 0}
Received capabilities
Number of elements: 3
OobUse: {'context': 0}
EcdhSecret: {'context': 0}
Provisioning complete
    Address(es): 0x10-0x12
    Device key: 26ed34d9ce3afb941401a430f7365684
    Network key: 18eed9c2a56add85049ffc3c59ad0e12
Adding device key to subnet %d 0
Adding publication address of root element
len_prov = 1
uuid =  1578bc42364ea4409a9b364acb9bf093
{'1578bc42364ea4409a9b364acb9bf093': (8, 0)}
liste des node provisionnés = [bytearray(b'\x15x\xbcB6N\xa4@\x9a\x9b6J\xcb\x9b\xf0\x93')]
unprov liste = [bytearray(b'\xeb\x1b\xe7QI\xde}N\xa9\xf4\xe6zI\x7f\xea\xaf')]
prov_list ... = [bytearray(b'\x15x\xbcB6N\xa4@\x9a\x9b6J\xcb\x9b\xf0\x93'), bytearray(b'\xeb\x1b\xe7QI\xde}N\xa9\xf4\xe6zI\x7f\xea\xaf')]
unprov liste = []
DevkeyAdd: {'devkey_handle': 8}
AddrPublicationAdd: {'address_handle': 0}
Provision: {'context': 0}
Received capabilities
Number of elements: 1
OobUse: {'context': 0}
EcdhSecret: {'context': 0}
Provisioning complete
    Address(es): 0x13-0x13
    Device key: 470a4f2755a63b453e93e786740b643c
    Network key: 18eed9c2a56add85049ffc3c59ad0e12
Adding device key to subnet %d 0
Adding publication address of root element
len_prov = 2
uuid =  eb1be75149de7d4ea9f4e67a497feaaf
{'1578bc42364ea4409a9b364acb9bf093': (8, 0), 'eb1be75149de7d4ea9f4e67a497feaaf': (9, 1)}
liste des node provisionnés = [bytearray(b'\x15x\xbcB6N\xa4@\x9a\x9b6J\xcb\x9b\xf0\x93'), bytearray(b'\xeb\x1b\xe7QI\xde}N\xa9\xf4\xe6zI\x7f\xea\xaf')]
DevkeyAdd: {'devkey_handle': 9}
AddrPublicationAdd: {'address_handle': 1}

i now config the server :
cc = ConfigurationClient(db)
device.model_add(cc)
cc.publish_set(key_handle,addr_handle)
6) cc.composition_data_get()
received composition data (page {}): 0 {
"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"
},
{
"modelId": "1000"
}
]
}
]
}
7) cc.appkey_add(0)
8) cc.model_app_bind(db.nodes[node_id].unicast_address, 0, mt.ModelId(0x1000))
Appkey bind 0 succeded for subnet 0 at node 19
Model app bind status: AccessStatus.SUCCESS
Appkey bind 0 to model 1000 at 0013

9) cc.model_publication_set(db.nodes[node_id].unicast_address, mt.ModelId(0x1000), mt.Publish(db.groups[0].address, index=0, ttl=1))
Publication status for 1000 at element 19 to {'address': c001, 'index': 0, 'ttl': 1, 'period': 0, 'retransmit': {'count': 0, 'interval_steps': 0, 'interval': 50}, 'credentials': <FriendshipCredentials.DISABLED: 0>}

So after this logs, for me everytings works fine and I have my server that can publish to the group address 0. You see that in the Json file I already send.

Now then I configure the client, The device is already provisionned since I made a loop (as said above).
Now I configure the client that must subscribe to the group address :
1) cc.composition_data_get()
received composition data (page {}): 0 {
  "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"
        }
      ]
    }
  ]
}

2) cc.appkey_add(0)
3) cc.model_app_bind(db.nodes[node_id].unicast_address + 1, 0, mt.ModelId(0x1001))
Appkey bind 0 succeded for subnet 0 at node 16
Model app bind status: AccessStatus.SUCCESS
Appkey bind 0 to model 1001 at 0011

4) cc.model_subscription_add(db.nodes[node_id].unicast_address + 1, db.groups[0].address, mt.ModelId(0x1001))
Added subscription c001 to model 1001 at element 17

And that's it. Now my server and client are configured (as written in the tutorial).
I do now : gc.set(True)
Of course before I configure the GenericOnOffClient :
  gc = GenericOnOffClient()
  device.model_add(gc)
  gc.publish_set(0, 1) --> the server board correspond to (0,1)

With the gc.set(true) The led on the server board turn on (what is just because the device is well binded).
But nothing happen on the Client board. I don't see where the "publication" and "subscribe" act here ?
I though the server should publish to the group address when I do "gc.set(True)" and that the client should receive this state change because he subscribe and so the led on the client board should also turn on.
Is it just that the client receive the info correctly but it is not implemented that the led turn on ?
Can you explain me what I should see ?

Thanks !! I hope you have all information needed.

[Hung Bui]

Hi Valentin, 

If you also set the client to subscribe to the same publication address of the server then you should be able to receive the status message on the client. 
Please check the logging on the client. 
Note that the guide in the .md could be a bit out of date. The new implementation of the light switch client in SDK v4.x doesn't update LEDs but only printout log. 

https://infocenter.nordicsemi.com/topic/com.nordic.infocenter.meshsdk.v4.1.0/md_examples_light_switch_client_README.html?cp=7_2_3_0_1

[ValentinL]

Ok so you mean my client certainly receive the status with my implementation (see below).
i'll try to check the log on the client board.