Static Provisioner - ACCESS_STATUS_INSUFFICIENT_RESOURCES

[MSEE]

Hi, 

I have a problem with the BLE mesh light example using the static provisioner. I have modified the example to have multiple Generic OnOff servers. Client and Servers are working using nRF mesh to provision and set up publish/subscribe.

I have modified the configuration steps in the provision code to be able to setup all generic OnOff as i wanted. It have been working to subscribe to the client but when i added a publish configuration step i get an error. I have tried to limit the steps and changed to only publishing from the servers to the client and that is also working.

I'm getting opcode error 5. 

<t:    2212109>, node_setup.c,  289, opcode status field: 5 

Which is

ACCESS_STATUS_INSUFFICIENT_RESOURCES             = 0x05, /**< The node cannot store provided information due to insufficient resources on node. */

I'm having a hard time to debug this i dont understand what the insufficient resources on the node actually means and how to fix it whether it is on the Provision device or Server node?

Thanks,
Michael

[MSEE]

Hi Simon,

Unfortunately it did not seem to work. I used the Serial provision and had enabled offloading on the provisioneer. Confirmed the offloading was enabled and working, output below. 

main.c,   77, ----- Bluetooth Mesh Serial Interface Application -----
main.c,   63, Enabling ECDH offloading...
main.c,   66, Initializing serial interface...
serial_handler_prov.c,  267, Generating encryption keypair...
main.c,   87, Initialization complete!
mesh_app_utils.c,   65, Device UUID (raw): FAB30A2AA21D9B4F9851E2375CC43CC2
mesh_app_utils.c,   70, Device UUID : 2A0AB3FA-1DA2-4F9B-9851-E2375CC43CC2
main.c,   98, Bluetooth Mesh Serial Interface Application started!

Provisioned and tried to configure the node the same as static provisioneer but i still got AccessStatus.INSUFFICIENT_RESOURCES when trying to add publication. 

pyACI:

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

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

In [3]: 2019-05-17 10:55:57,692 - INFO - COM4: Success
2019-05-17 10:55:57,696 - INFO - COM4: Success
2019-05-17 10:55:57,702 - INFO - COM4: SubnetAdd: {'subnet_handle': 0}
2019-05-17 10:55:57,707 - INFO - COM4: AppkeyAdd: {'appkey_handle': 0}
2019-05-17 10:55:57,713 - INFO - COM4: AppkeyAdd: {'appkey_handle': 1}
In [3]: p.scan_start()

In [4]: 2019-05-17 10:56:00,373 - INFO - COM4: Success
2019-05-17 10:56:01,113 - INFO - COM4: Received UUID 450cf845108b6c4480c73736a1cbc479 with RSSI: -18 dB
In [4]: p.scan_stop()

In [5]: 2019-05-17 10:56:03,929 - INFO - COM4: Success
In [5]: p.provision(name="lightBulb1")

In [6]: 2019-05-17 10:56:08,569 - INFO - COM4: Provision: {'context': 0}
2019-05-17 10:56:08,582 - INFO - COM4: Link established
2019-05-17 10:56:08,637 - INFO - COM4: Received capabilities
2019-05-17 10:56:08,638 - INFO - COM4: Number of elements: 2
2019-05-17 10:56:08,642 - INFO - COM4: OobUse: {'context': 0}
2019-05-17 10:56:08,840 - INFO - COM4: ECDH request received
2019-05-17 10:56:08,848 - INFO - COM4: EcdhSecret: {'context': 0}
2019-05-17 10:56:09,168 - INFO - COM4: Provisioning complete
2019-05-17 10:56:09,168 - INFO - COM4:  Address(es): 0x10-0x11
2019-05-17 10:56:09,169 - INFO - COM4:  Device key: a5afe5f29aaa252b40c9c81c8273ef2e
2019-05-17 10:56:09,171 - INFO - COM4:  Network key: 18eed9c2a56add85049ffc3c59ad0e12
2019-05-17 10:56:09,172 - INFO - COM4: Adding device key to subnet 0
2019-05-17 10:56:09,173 - INFO - COM4: Adding publication address of root element
2019-05-17 10:56:09,178 - INFO - COM4: DevkeyAdd: {'devkey_handle': 8}
2019-05-17 10:56:09,179 - INFO - COM4: AddrPublicationAdd: {'address_handle': 0}
2019-05-17 10:56:09,270 - INFO - COM4: Provisioning link closed
In [6]: cc = ConfigurationClient(db)

In [7]: device.model_add(cc)

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

In [9]: cc.composition_data_get()

In [10]: 2019-05-17 10:56:42,685 - INFO - COM4: PacketSend: {'token': 1}
2019-05-17 10:56:42,690 - INFO - COM4: {event: MeshTxComplete, data: {'token': 1}}
2019-05-17 10:56:43,324 - INFO - COM4.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"
        },
        {
          "modelId": "1000"
        }
      ]
    },
    {
      "index": 1,
      "location": "0000",
      "models": [
        {
          "modelId": "1000"
        }
      ]
    }
  ]
}
In [10]: cc.appkey_add(0)

In [11]: 2019-05-17 10:56:52,964 - INFO - COM4: PacketSend: {'token': 2}
2019-05-17 10:56:53,005 - INFO - COM4: {event: MeshTxComplete, data: {'token': 2}}
2019-05-17 10:56:53,029 - INFO - COM4.ConfigurationClient: Appkey status: AccessStatus.SUCCESS
2019-05-17 10:56:53,032 - INFO - COM4.ConfigurationClient: Appkey add 0 succeded for subnet 0 at node 0010
In [11]: cc.model_app_bind(db.nodes[0].unicast_address,0,mt.ModelId(0x1000))

In [12]: 2019-05-17 10:57:00,256 - INFO - COM4: PacketSend: {'token': 3}
2019-05-17 10:57:00,262 - INFO - COM4: {event: MeshTxComplete, data: {'token': 3}}
2019-05-17 10:57:00,273 - INFO - COM4.ConfigurationClient: Model app bind status: AccessStatus.SUCCESS
2019-05-17 10:57:00,276 - INFO - COM4.ConfigurationClient: Appkey bind 0 to model 1000 at 0010
In [12]:
    ...: cc.model_app_bind(db.nodes[0].unicast_address+1,0,mt.ModelId(0x1000))

In [13]: 2019-05-17 10:57:07,825 - INFO - COM4: PacketSend: {'token': 4}
2019-05-17 10:57:07,841 - INFO - COM4: {event: MeshTxComplete, data: {'token': 4}}
2019-05-17 10:57:07,856 - INFO - COM4.ConfigurationClient: Model app bind status: AccessStatus.SUCCESS
2019-05-17 10:57:07,859 - INFO - COM4.ConfigurationClient: Appkey bind 0 to model 1000 at 0011
In [13]: d[0].send(cmd.AddrPublicationAdd(db.nodes[0].unicast_address+1))

In [14]: 2019-05-17 10:57:14,741 - INFO - COM4: AddrPublicationAdd: {'address_handle': 1}
In [14]: gc = GenericOnOffClient()

In [15]: device.model_add(gc)

In [16]: gc.publish_set(0,0)

In [17]: gc.set(True)

In [18]: 2019-05-17 10:57:39,369 - INFO - COM4: PacketSend: {'token': 5}
2019-05-17 10:57:39,383 - INFO - COM4: {event: MeshTxComplete, data: {'token': 5}}
2019-05-17 10:57:39,396 - INFO - COM4.GenericOnOffClient: Present OnOff: on
In [18]: gc.set(False)

In [19]: 2019-05-17 10:57:46,046 - INFO - COM4: PacketSend: {'token': 6}
2019-05-17 10:57:46,060 - INFO - COM4: {event: MeshTxComplete, data: {'token': 6}}
2019-05-17 10:57:46,078 - INFO - COM4.GenericOnOffClient: off
In [19]: gc1 = GenericOnOffClient()

... 

In [21]: device.model_add(gc1)

In [22]: gc1.publish_set(0,1)

In [23]: gc1.set(True)

In [24]: 2019-05-17 10:58:36,088 - INFO - COM4: PacketSend: {'token': 7}
2019-05-17 10:58:36,097 - INFO - COM4: {event: MeshTxComplete, data: {'token': 7}}
2019-05-17 10:58:36,122 - INFO - COM4.GenericOnOffClient: Present OnOff: on
2019-05-17 10:58:36,124 - INFO - COM4.GenericOnOffClient: Present OnOff: on
In [24]: gc1.set(False)

In [25]: 2019-05-17 10:58:41,347 - INFO - COM4: PacketSend: {'token': 8}
2019-05-17 10:58:41,354 - INFO - COM4: {event: MeshTxComplete, data: {'token': 8}}
2019-05-17 10:58:41,375 - INFO - COM4.GenericOnOffClient: off
2019-05-17 10:58:41,376 - INFO - COM4.GenericOnOffClient: off
In [25]: cc.model_subscription_add(db.nodes[0].unicast_address,0xC001, mt.ModelId(0x1000))

In [26]: 2019-05-17 10:58:58,920 - INFO - COM4: PacketSend: {'token': 9}
2019-05-17 10:58:58,936 - INFO - COM4: {event: MeshTxComplete, data: {'token': 9}}
2019-05-17 10:58:58,956 - INFO - COM4.ConfigurationClient: Model subscription status: AccessStatus.SUCCESS
2019-05-17 10:58:58,959 - INFO - COM4.ConfigurationClient: Added subscription 'c001' to model 1000 at element 0010
In [26]: cc.model_subscription_add(db.nodes[0].unicast_address,0xC000, mt.ModelId(0x1000))

In [27]: 2019-05-17 10:59:06,737 - INFO - COM4: PacketSend: {'token': 10}
2019-05-17 10:59:06,741 - INFO - COM4: {event: MeshTxComplete, data: {'token': 10}}
2019-05-17 10:59:06,760 - INFO - COM4.ConfigurationClient: Model subscription status: AccessStatus.SUCCESS
2019-05-17 10:59:06,764 - INFO - COM4.ConfigurationClient: Added subscription 'c000' to model 1000 at element 0010
In [27]: cc.model_subscription_add(db.nodes[0].unicast_address+1,0xC000, mt.ModelId(0x1000))

In [28]: 2019-05-17 10:59:13,337 - INFO - COM4: PacketSend: {'token': 11}
2019-05-17 10:59:13,352 - INFO - COM4: {event: MeshTxComplete, data: {'token': 11}}
2019-05-17 10:59:13,371 - INFO - COM4.ConfigurationClient: Model subscription status: AccessStatus.SUCCESS
2019-05-17 10:59:13,374 - INFO - COM4.ConfigurationClient: Added subscription 'c000' to model 1000 at element 0011
In [28]: cc.model_subscription_add(db.nodes[0].unicast_address+1,0xC002, mt.ModelId(0x1000))

In [29]: 2019-05-17 10:59:19,969 - INFO - COM4: PacketSend: {'token': 12}
2019-05-17 10:59:19,976 - INFO - COM4: {event: MeshTxComplete, data: {'token': 12}}
2019-05-17 10:59:19,996 - INFO - COM4.ConfigurationClient: Model subscription status: AccessStatus.SUCCESS
2019-05-17 10:59:19,999 - INFO - COM4.ConfigurationClient: Added subscription 'c002' to model 1000 at element 0011


In [29]: cc.model_publication_set(db.nodes[0].unicast_address+1,mt.ModelId(0x1000), mt.Publish(0xCEEE, index=0,ttl=1))

In [30]: 2019-05-17 10:59:57,101 - INFO - COM4: PacketSend: {'token': 13}
2019-05-17 10:59:57,146 - INFO - COM4: {event: MeshTxComplete, data: {'token': 13}}
2019-05-17 10:59:57,199 - INFO - COM4.ConfigurationClient: Model publication status: AccessStatus.INSUFFICIENT_RESOURCES

Best Regards,

Michael

[Mathias]

Hi,

Where you able to fix this memory problem? I have the same problem with roughly the same setup.

Kind regards,

Mathias