This post is older than 2 years and might not be relevant anymore
More Info: Consider searching for newer posts

Serial example throw an error when PyACI runs command "gc.set(False)"

Dear friends,

My 52840 DK flashed a serial example(nrf5_SDK_for_Mesh_v5.0.0_src\examples\serial) as a provisioner. However, the 52840 throws an error message when I input a control command about four times. At first, the cmd " gc.set(False)" executed well.  

below is the PyACI log:

PS E:\bluemesh\fortest\nrf5_SDK_for_Mesh_v5.0.0_src\scripts\interactive_pyaci> C:\Users\admin\AppData\Local\Programs\Python\Python38\python.exe interactive_pyaci.py -d COM4

    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.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]: db = MeshDB("database/example_database.json")

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

In [3]: 2021-07-06 11:18:12,513 - INFO - COM4: Success
2021-07-06 11:18:12,514 - INFO - COM4: Success
2021-07-06 11:18:12,518 - INFO - COM4: SubnetAdd: {'subnet_handle': 0}
2021-07-06 11:18:12,520 - INFO - COM4: AppkeyAdd: {'appkey_handle': 0}
2021-07-06 11:18:12,524 - INFO - COM4: AppkeyAdd: {'appkey_handle': 1}
In [3]:

In [3]:

In [3]: device.send(cmd.DevkeyAdd(db.nodes[0].unicast_address, 0, db.nodes[0].device_key))

In [4]: 2021-07-06 11:18:18,062 - INFO - COM4: DevkeyAdd: {'devkey_handle': 8}
In [4]:

In [4]: device.send(cmd.AddrPublicationAdd(db.nodes[0].unicast_address))

In [5]: 2021-07-06 11:18:23,673 - INFO - COM4: AddrPublicationAdd: {'address_handle': 0}
In [5]:

In [5]:

In [5]: cc = ConfigurationClient(db)

In [6]: device.model_add(cc)

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

In [8]: cc.composition_data_get()

In [9]: 2021-07-06 11:19:14,936 - INFO - COM4: PacketSend: {'token': 1}
2021-07-06 11:19:14,958 - INFO - COM4: {event: MeshTxComplete, data: {'token': 1}}
In [9]:

In [9]: cc.composition_data_get()

In [10]: 2021-07-06 11:19:16,339 - INFO - COM4: PacketSend: {'token': 2}
2021-07-06 11:19:16,363 - INFO - COM4: {event: MeshTxComplete, data: {'token': 2}}
In [10]: cc.composition_data_get()

In [11]: 2021-07-06 11:19:17,564 - INFO - COM4: PacketSend: {'token': 3}
2021-07-06 11:19:17,587 - INFO - COM4: {event: MeshTxComplete, data: {'token': 3}}
In [11]: cc.composition_data_get()

In [12]: 2021-07-06 11:19:18,451 - INFO - COM4: PacketSend: {'token': 4}
2021-07-06 11:19:18,475 - INFO - COM4: {event: MeshTxComplete, data: {'token': 4}}
In [12]:

In [12]: cc.composition_data_get()

In [13]: 2021-07-06 11:19:19,795 - INFO - COM4: PacketSend: {'token': 5}
2021-07-06 11:19:19,815 - INFO - COM4: {event: MeshTxComplete, data: {'token': 5}}
In [13]: cc.composition_data_get()

In [14]: 2021-07-06 11:19:20,713 - INFO - COM4: PacketSend: {'token': 6}
2021-07-06 11:19:20,737 - INFO - COM4: {event: MeshTxComplete, data: {'token': 6}}
In [14]:

In [14]: cc.composition_data_get()

In [15]: 2021-07-06 11:19:22,527 - INFO - COM4: PacketSend: {'token': 7}
2021-07-06 11:19:22,553 - INFO - COM4: {event: MeshTxComplete, data: {'token': 7}}
In [15]:

In [15]:

In [15]: cc.composition_data_get()

In [16]: 2021-07-06 11:19:24,148 - INFO - COM4: PacketSend: {'token': 8}
2021-07-06 11:19:24,170 - INFO - COM4: {event: MeshTxComplete, data: {'token': 8}}
In [16]:

In [16]:

In [16]: device.send(cmd.NetStateSet(287454020, 0, 0, 0))

In [17]: 2021-07-06 11:19:34,774 - INFO - COM4: {event: MeshIvEntrySetNotification, data: {'iv_index': 287454020, 'iv_update_in_progress': 0, 'iv_update_timeout_counter': 0}}
2021-07-06 11:19:34,775 - INFO - COM4: {event: MeshIvUpdateNotification, data: {'iv_index': 287454020}}
2021-07-06 11:19:34,775 - INFO - COM4: {event: MeshSeqnumEntrySetNotification, data: {'next_block': 8192}}
2021-07-06 11:19:34,776 - INFO - COM4: Success
In [17]:

In [17]: cc.composition_data_get()

In [18]: 2021-07-06 11:19:45,636 - INFO - COM4: PacketSend: {'token': 9}
2021-07-06 11:19:45,661 - INFO - COM4: {event: MeshTxComplete, data: {'token': 9}}
2021-07-06 11:19:46,518 - INFO - COM4.ConfigurationClient: Received composition data (page 0x00): {
  "cid": "0211",
  "pid": "0302",
  "vid": "2431",
  "crpl": 105,
  "features": {
    "relay": 0,
    "proxy": 0,
    "friend": 0,
    "low_power": 2
  },
  "elements": [
    {
      "index": 0,
      "location": "0000",
      "models": [
        {
          "modelId": "0000"
        },
        {
          "modelId": "0002"
        },
        {
          "modelId": "0003"
        },
        {
          "modelId": "1000"
        },
        {
          "modelId": "1002"
        },
        {
          "modelId": "1004"
        },
        {
          "modelId": "1006"
        },
        {
          "modelId": "1007"
        },
        {
          "modelId": "1300"
        },
        {
          "modelId": "1301"
        },
        {
          "modelId": "1303"
        },
        {
          "modelId": "1304"
        },
        {
          "modelId": "02110000"
        }
      ]
    },
    {
      "index": 1,
      "location": "0000",
      "models": [
        {
          "modelId": "1002"
        },
        {
          "modelId": "1306"
        }
      ]
    }
  ]
}
In [18]:

In [18]:

In [18]:

In [18]: gc = GenericOnOffClient()
    ...: device.model_add(gc)
    ...: gc.publish_set(0, 0)

In [19]:

In [19]: gc.set(False)

In [20]: 2021-07-06 11:21:27,399 - INFO - COM4: PacketSend: {'token': 10}
2021-07-06 11:21:27,420 - INFO - COM4: {event: MeshTxComplete, data: {'token': 10}}
2021-07-06 11:21:27,446 - INFO - COM4.GenericOnOffClient: Present OnOff: onoff Remaining time: 1000 ms
In [20]:

In [20]: gc.set(False)

In [21]: 2021-07-06 11:21:36,495 - INFO - COM4: PacketSend: {'token': 11}
2021-07-06 11:21:36,518 - INFO - COM4: {event: MeshTxComplete, data: {'token': 11}}
2021-07-06 11:21:36,539 - INFO - COM4.GenericOnOffClient: off
In [21]:

In [21]: gc.set(False)

In [22]: gc.set(False)

In [23]: gc.set(False)

In [24]: gc.set(False)

In [25]: gc.set(False)2021-07-06 11:22:52,174 - INFO - COM4: cmd PacketSend, timeout waiting for event
In [25]: gc.set(False)

In [26]: 2021-07-06 11:22:54,181 - INFO - COM4: cmd PacketSend, timeout waiting for event
2021-07-06 11:22:56,187 - INFO - COM4: cmd PacketSend, timeout waiting for event
2021-07-06 11:22:58,193 - INFO - COM4: cmd PacketSend, timeout waiting for event

below is the 52840 log:

<t:          0>, main.c,  102, ----- Bluetooth Mesh Serial Interface Application -----
<t:      13278>, main.c,   88, Enabling ECDH offloading...
<t:      13282>, main.c,   91, Initializing serial interface...
<t:      13284>, serial_handler_prov.c,  267, Generating encryption keypair...
<t:      18140>, main.c,  111, Initialization complete!
<t:      18143>, mesh_app_utils.c,   66, Device UUID (raw): B678D348094E4856A7661247E660F05C
<t:      18146>, mesh_app_utils.c,   67, Device UUID : B678D348-094E-4856-A766-1247E660F05C
<t:      18157>, main.c,  122, Bluetooth Mesh Serial Interface Application started!
<t:      18161>, main.c,  125, PERSISTENT_STORAGE is set!
<t:    2721861>, network.c,  304, TX sequence_number: 0, iv_index: 0
<t:    2767826>, network.c,  304, TX sequence_number: 1, iv_index: 0
<t:    2807992>, network.c,  304, TX sequence_number: 2, iv_index: 0
<t:    2837062>, network.c,  304, TX sequence_number: 3, iv_index: 0
<t:    2881092>, network.c,  304, TX sequence_number: 4, iv_index: 0
<t:    2911150>, network.c,  304, TX sequence_number: 5, iv_index: 0
<t:    2970622>, network.c,  304, TX sequence_number: 6, iv_index: 0
<t:    3023725>, network.c,  304, TX sequence_number: 7, iv_index: 0
<t:    3727817>, network.c,  304, TX sequence_number: 0, iv_index: 287454020
<t:    3728933>, net_packet.c,  228, Unencrypted data: : 0002004CB7CFDB8EE936
<t:    3728936>, network.c,  356, RX sequence_number: 0, iv_index: 287454020 dst: 2 src: 1 ttl: 7
<t:    3729182>, net_packet.c,  228, Unencrypted data: : 0001802E2804498BF4C0306B366BF292E047
<t:    3729186>, network.c,  356, RX sequence_number: 2954, iv_index: 287454020 dst: 1 src: 2 ttl: 10
<t:    3729191>, transport.c,  931, Got segment 0
<t:    3736213>, net_packet.c,  228, Unencrypted data: : 0001802E2824ED427255D2D4B69E32FBDB91
<t:    3736216>, network.c,  356, RX sequence_number: 2955, iv_index: 287454020 dst: 1 src: 2 ttl: 9
<t:    3736221>, transport.c,  931, Got segment 1
<t:    3742674>, net_packet.c,  228, Unencrypted data: : 0001802E2844DF45B4EBD9E4D7C85866CCE1
<t:    3742678>, network.c,  356, RX sequence_number: 2956, iv_index: 287454020 dst: 1 src: 2 ttl: 10
<t:    3742683>, transport.c,  931, Got segment 2
<t:    3747216>, transport.c,  611, Sending ACK...
<t:    3747219>, network.c,  304, TX sequence_number: 1, iv_index: 287454020
<t:    3748473>, net_packet.c,  228, Unencrypted data: : 0002002E2800000007
<t:    3748476>, network.c,  356, RX sequence_number: 1, iv_index: 287454020 dst: 2 src: 1 ttl: 7
<t:    3749916>, net_packet.c,  228, Unencrypted data: : 0001802E286424CF62B065AFC530699FC060
<t:    3749919>, network.c,  356, RX sequence_number: 2957, iv_index: 287454020 dst: 1 src: 2 ttl: 9
<t:    3749924>, transport.c,  931, Got segment 3
<t:    3756462>, net_packet.c,  228, Unencrypted data: : 0001802E2884EBAD9AC9481E1651
<t:    3756465>, network.c,  356, RX sequence_number: 2958, iv_index: 287454020 dst: 1 src: 2 ttl: 10
<t:    3756470>, transport.c,  931, Got segment 4
<t:    3756473>, transport.c,  611, Sending ACK...
<t:    3756477>, network.c,  304, TX sequence_number: 2, iv_index: 287454020
<t:    3756490>, transport.c, 1045, Message decrypted
<t:    7062384>, network.c,  304, TX sequence_number: 3, iv_index: 287454020
<t:    7063311>, net_packet.c,  228, Unencrypted data: : 00024DB8A2D7E14E9CCF17
<t:    7063315>, network.c,  356, RX sequence_number: 3, iv_index: 287454020 dst: 2 src: 1 ttl: 7
<t:    7063825>, net_packet.c,  228, Unencrypted data: : 00014DFA0E642798AB941B34
<t:    7063828>, network.c,  356, RX sequence_number: 2959, iv_index: 287454020 dst: 1 src: 2 ttl: 9
<t:    7063835>, transport.c, 1045, Message decrypted
<t:    7360432>, network.c,  304, TX sequence_number: 4, iv_index: 287454020
<t:    7361795>, net_packet.c,  228, Unencrypted data: : 00014DD32E093ECE3D45
<t:    7361798>, network.c,  356, RX sequence_number: 2960, iv_index: 287454020 dst: 1 src: 2 ttl: 10
<t:    7361806>, transport.c, 1045, Message decrypted
<t:    7362815>, net_packet.c,  228, Unencrypted data: : 00024D3F3830AC11AC30E0
<t:    7362818>, network.c,  356, RX sequence_number: 4, iv_index: 287454020 dst: 2 src: 1 ttl: 7
<t:    7466803>, net_packet.c,  228, Unencrypted data: : FFFF4D8F925E9CCECA61C9F29954
<t:    7466806>, network.c,  356, RX sequence_number: 641, iv_index: 287454020 dst: 65535 src: 45 ttl: 10
<t:    7466813>, transport.c, 1045, Message decrypted
<t:    7466819>, app_error_weak.c,  105, Mesh assert at 0x00030F76 (:0)

and the IDE shows:

I can't find the reason for this error. Could you give me a hand?

Thanks.

Best regards,

Oplinux

Related