Automating Nordic BLE Mesh Provisioning

Purpose

This document will show how to automate the provisioning process for Nordic BLE Mesh nodes using Python scripting.  When provisioning nodes using PyACI (Python Application Controller Interface), the Interactive Python shell is used to type in provisioning commands.  However, this process can be automated by putting the commands in a script that is run automatically.

Modifications

In order to be able to automate this process, some modifications were required to the PyACI source code.  In specific, the ConfigurationClient object in config.py was patched to provide blocking calls.  In the original code, methods of this object are non-blocking which return immediately.  A callback function is invoked once the results of the command are returned from the remote node over RF.  For scripting purposes, this is problematic since a script should be monotonic with each command passing or failing.  If a command fails, the script should abort or raise an exception to notify the user or appropriate error handling (such as retrying).  The accompanying patch (attached) converts the non-blocking calls to blocking calls in [Mesh SDK 3.1.0]/scripts/interactive_pyaci/models/config.py.

Demonstration

The following Python script represents an example that can be extended to automate this process; save this to a file called command.txt:

from time import sleep
import sys

try:
    db = MeshDB("database/example_database.json")
    db.provisioners
    p = Provisioner(device, db)
    p.scan_start()
    sleep(3)
    p.scan_stop()
    p.provision(name="Light bulb #1")
    sleep(4)
    cc = ConfigurationClient(db, True)
    device.model_add(cc)
    cc.publish_set(8, 0)
    cc.composition_data_get()
except:
    print("Unexpected error:", sys.exc_info()[0])

The try block has the sample provisioning commands; if any failure occurs the exception will be caught in the exception block.  This script can be expanded to implement more intricate error handling and possible retries. 

To run the above script, we will pass it to PyACI via the command line shown below:

python interactive_pyaci.py -d COM20 -l 3 < command.txt

The serial port will be changed accordingly to the local machine, of course.  The “-l 3” command is to enable logging but is completely optional.

The above command redirects command.txt into the PyACI shell and it executes it within its environment.  Full Python programming language is available to the user at their disposal to make the script as intricate as needed.

As an example, this is the output of running the above command as it runs to completion without errors:

python interactive_pyaci.py -d COM20 -l 3 < commands.txt

    To control your device, use d[x], where x is the device index.
    Devices are indexed based on the order of the COM ports specified by the -d option.
    The first device, d[0], can also be accessed using device.

    Type d[x]. and hit tab to see the available methods.

Python 3.7.1 (v3.7.1:260ec2c36a, Oct 20 2018, 14:57:15) [MSC v.1915 64 bit (AMD64)]
Type 'copyright', 'credits' or 'license' for more information
IPython 7.0.1 -- An enhanced Interactive Python. Type '?' for help.

In [1]:
In [2]:
In [3]:
In [3]:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...: 2019-01-26 23:56:03,734 - INFO - COM20: Success
2019-01-26 23:56:03,749 - INFO - COM20: Success
2019-01-26 23:56:03,758 - INFO - COM20: SubnetAdd: {'subnet_handle': 0}
2019-01-26 23:56:03,763 - INFO - COM20: AppkeyAdd: {'appkey_handle': 0}
2019-01-26 23:56:03,767 - INFO - COM20: AppkeyAdd: {'appkey_handle': 1}
2019-01-26 23:56:03,774 - INFO - COM20: Success
2019-01-26 23:56:05,138 - INFO - COM20: Received UUID 5c8e16a4cdd378408297d12e7dd9ce68 with RSSI: -34 dB
2019-01-26 23:56:06,736 - INFO - COM20: Success
2019-01-26 23:56:06,742 - INFO - COM20: Provision: {'context': 0}
2019-01-26 23:56:06,747 - INFO - COM20: Link established
2019-01-26 23:56:06,813 - INFO - COM20: Received capabilities
2019-01-26 23:56:06,816 - INFO - COM20: Number of elements: 1
2019-01-26 23:56:06,822 - INFO - COM20: OobUse: {'context': 0}
2019-01-26 23:56:09,059 - INFO - COM20: ECDH request received
2019-01-26 23:56:09,072 - INFO - COM20: EcdhSecret: {'context': 0}
2019-01-26 23:56:09,379 - INFO - COM20: Provisioning complete
2019-01-26 23:56:09,382 - INFO - COM20:         Address(es): 0x36-0x36
2019-01-26 23:56:09,385 - INFO - COM20:         Device key: bbd765a44c53f8ac7b09e72d45c37770
2019-01-26 23:56:09,387 - INFO - COM20:         Network key: 18eed9c2a56add85049ffc3c59ad0e12
2019-01-26 23:56:09,390 - INFO - COM20: Adding device key to subnet 0
2019-01-26 23:56:09,393 - INFO - COM20: Adding publication address of root element
2019-01-26 23:56:09,423 - INFO - COM20: DevkeyAdd: {'devkey_handle': 8}
2019-01-26 23:56:09,442 - INFO - COM20: AddrPublicationAdd: {'address_handle': 0}
2019-01-26 23:56:09,472 - INFO - COM20: Provisioning link closed
2019-01-26 23:56:10,745 - INFO - COM20.ConfigurationClient: Sleeping 10
2019-01-26 23:56:10,750 - INFO - COM20: PacketSend: {'token': 1}
2019-01-26 23:56:10,754 - INFO - COM20: {event: MeshTxComplete, data: {'token': 1}}
2019-01-26 23:56:11,763 - INFO - COM20.ConfigurationClient: Sleeping 9
2019-01-26 23:56:12,768 - INFO - COM20.ConfigurationClient: Sleeping 8
2019-01-26 23:56:13,784 - INFO - COM20.ConfigurationClient: Sleeping 7
2019-01-26 23:56:14,797 - INFO - COM20.ConfigurationClient: Sleeping 6
2019-01-26 23:56:15,812 - INFO - COM20.ConfigurationClient: Sleeping 5
2019-01-26 23:56:16,826 - INFO - COM20.ConfigurationClient: Sleeping 4
2019-01-26 23:56:16,933 - INFO - COM20: Calling event handler
2019-01-26 23:56:16,970 - INFO - COM20.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"
        }
      ]
    }
  ]
}
2019-01-26 23:56:17,836 - INFO - COM20.ConfigurationClient: blocked = 0, timeout = 3

In [4]:
In [4]:
In [4]:
In [4]: Do you really want to exit ([y]/n)?

The cc.composition_data_get() command in the commands.txt script has been patched to be a blocking call.  As is seen in the debug output above, it has a sleeping countdown that counts down to ten seconds while waiting for a response from the remote node.  If a response is received within the allotted time, the command exits with no error.  Otherwise, an exception is thrown.

Now let us see a degenerate case where there are errors:

python interactive_pyaci.py -d COM20 -l 3 < commands.txt

    To control your device, use d[x], where x is the device index.
    Devices are indexed based on the order of the COM ports specified by the -d option.
    The first device, d[0], can also be accessed using device.

    Type d[x]. and hit tab to see the available methods.

Python 3.7.1 (v3.7.1:260ec2c36a, Oct 20 2018, 14:57:15) [MSC v.1915 64 bit (AMD64)]
Type 'copyright', 'credits' or 'license' for more information
IPython 7.0.1 -- An enhanced Interactive Python. Type '?' for help.

In [1]:
In [2]:
In [3]:
In [3]:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...:    ...: 2019-01-26 23:57:16,204 - INFO - COM20: Success
2019-01-26 23:57:16,219 - ERROR - COM20: None: ERROR_REJECTED
2019-01-26 23:57:16,226 - ERROR - COM20: SubnetAdd: ERROR_INTERNAL
2019-01-26 23:57:16,232 - ERROR - COM20: AppkeyAdd: ERROR_INTERNAL
2019-01-26 23:57:16,237 - ERROR - COM20: AppkeyAdd: ERROR_INTERNAL
2019-01-26 23:57:16,242 - INFO - COM20: Success
Unexpected error: <class 'IndexError'>

In [4]:
2019-01-26 23:57:19,212 - INFO - COM20: SuccessIn [4]:

In [4]:
In [4]: Do you really want to exit ([y]/n)?

The Unexpected error: <class 'IndexError'> is from the exception block of the commands.txt script.  This demonstrates the script handling an error in the execution of the script.

  • I’m prompted while using the surpassing in addition to preachy checklist you give in such very little timing. angolan suurlähetystö Intiassa

  • Hi mark,

    I got none message about provisionee when i type in cc.composition_data_get(). Do you know the reason? thanks.

    E:\bluemesh\nrf5_SDK_for_Mesh_v5.0.0_src\scripts\interactive_pyaci> python interactive_pyaci.py -d COM4 --no-logfile
    
        To control your device, use d[x], where x is the device index.
        Devices are indexed based on the order of the COM ports specified by the -d option.
        The first device, d[0], can also be accessed using device.
    
        Type d[x]. and hit tab to see the available methods.
    
    2021-05-11 13:48:41,503 - INFO - COM4: Device rebooted.
    Python 3.8.6 (tags/v3.8.6:db45529, Sep 23 2020, 15:52:53) [MSC v.1927 64 bit (AMD64)]
    Type 'copyright', 'credits' or 'license' for more information
    IPython 7.23.1 -- An enhanced Interactive Python. Type '?' for help.
    
    In [1]:
    
    In [1]:
    
    In [1]:
    
    In [1]: db = MeshDB("database/example_database.json")
    
    In [2]: db.provisioners
    Out[2]: [{'name': 'BT Mesh Provisioner', 'UUID': _UUID(b'\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00'), 'allocated_unicast_range': [{'low_address': 0010, 'high_address': 7fff}], 'allocated_group_range': [{'low_address': c000, 'high_address': feff}]}]
    
    In [3]: p = Provisioner(device, db)
    
    In [4]: 2021-05-11 13:49:05,887 - INFO - COM4: Success
    2021-05-11 13:49:05,890 - INFO - COM4: Success
    2021-05-11 13:49:05,891 - INFO - COM4: SubnetAdd: {'subnet_handle': 0}
    2021-05-11 13:49:05,894 - INFO - COM4: AppkeyAdd: {'appkey_handle': 0}
    2021-05-11 13:49:05,896 - INFO - COM4: AppkeyAdd: {'appkey_handle': 1}
    In [4]:
    
    In [4]: p.scan_start()
    
    2021-05-11 13:49:16,430 - INFO - COM4: Success
    In [5]: 2021-05-11 13:49:16,873 - INFO - COM4: Received UUID 005955aa00000000c10130f48247099f with RSSI: -18 dB
    2021-05-11 13:49:18,240 - INFO - COM4: Received UUID c1926b4e348db03389b14bad953ed730 with RSSI: -59 dB
    In [5]: p.scan_stop()
    
    In [6]: 2021-05-11 13:49:23,790 - INFO - COM4: Success
    In [6]:
    
    In [6]: p.provision(name="Light bulb")
    
    In [7]: 2021-05-11 13:49:54,120 - INFO - COM4: Provision: {'context': 0}
    2021-05-11 13:49:54,132 - INFO - COM4: Link established
    2021-05-11 13:49:54,185 - INFO - COM4: Received capabilities
    2021-05-11 13:49:54,185 - INFO - COM4: Number of elements: 1
    2021-05-11 13:49:54,188 - INFO - COM4: OobUse: {'context': 0}
    2021-05-11 13:49:54,420 - INFO - COM4: ECDH request received
    2021-05-11 13:49:54,426 - INFO - COM4: EcdhSecret: {'context': 0}
    2021-05-11 13:49:56,679 - INFO - COM4: Provisioning complete
    2021-05-11 13:49:56,680 - INFO - COM4:  Address(es): 0x10-0x10
    2021-05-11 13:49:56,681 - INFO - COM4:  Device key: b850e5c017d6004aae0ef061b8b12900
    2021-05-11 13:49:56,681 - INFO - COM4:  Network key: 18eed9c2a56add85049ffc3c59ad0e12
    2021-05-11 13:49:56,682 - INFO - COM4: Adding device key to subnet 0
    2021-05-11 13:49:56,682 - INFO - COM4: Adding publication address of root element
    2021-05-11 13:49:56,686 - INFO - COM4: DevkeyAdd: {'devkey_handle': 8}
    2021-05-11 13:49:56,687 - INFO - COM4: AddrPublicationAdd: {'address_handle': 0}
    2021-05-11 13:49:56,794 - INFO - COM4: Provisioning link closed
    In [7]:
    
    In [7]:
    
    In [7]: cc = ConfigurationClient(db)
    
    In [8]: device.model_add(cc)
    
    In [9]: cc.publish_set(8, 0)
    
    In [10]:
    
    In [10]: cc.composition_data_get()
    
    2021-05-11 13:51:08,442 - INFO - COM4: PacketSend
    In [11]:
    
    In [11]:
    
    In [11]: cc.composition_data_get()
    
    2021-05-11 13:52:54,177 - INFO - COM4: PacketSend
    In [12]:
    
    In [12]:
    
    In [12]:
    
    In [12]:

  • After following all the steps, I'm running this on RasPi 4 with the command : 

            

    sudo python3 interactive_pyaci.py -d /dev/ttyACM1 -l 3 < command.txt

    And it stops at line 16 in the first output shown in this article. If I remove the error catching functionality, the script executes successfully. I also tried wrapping the try-except block inside a function and calling it at the end, and that didn't work too. You've mentioned that full python programming is available to extend the functionalities but that doesn't seem so for me. Do you have any insights ?