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

sensor_server with 5 Property IDs always failed in getting configuration (compositon_data_get) step using nRF Mesh (Android)

Hi,

My development setup:

HW:  nRF52840 DK
SDK: nrf5_SDK_for_Mesh_v5.0.0_src + nRF5_SDK_17.0.2_d674dde + s140nrf52720
Provisioner: nRF Mesh Android app (Ver 3.1.0)

-----------------------------------------------------------------------------------

I modified sensor_server example (nrf5_SDK_for_Mesh_v5.0.0_src\examples\sensor\server) to support multiple Property IDs (2 to 5)

Below are the Property ID I used in the modified sensor_server app: 

#define SENSOR_MOTION_SENSED_PROPERTY_ID (0x0042)
#define SENSOR_PRESENCE_DETECT_PROPERTY_ID (0x004D)
#define SENSOR_PRESENT_AMBIENT_TEMPERATURE_PROPERTY_ID (0x004F)
#define SENSOR_PRESENT_AMBIENT_RELATIVE_HUMIDITY_PROPERTY_ID (0x0076)
#define SENSOR_PRESENT_AMBIENT_VOC_PROPERTY_ID (0x0078)

I have tried adding UP TO 4 Property IDs (and up to 4 descriptors), everything is working fine, i.e. able to get through provisioning and configuration successfully and work fine with sensor_client app to send the descriptor msg for all property ids and other test (per the sensor example)

   

Problem statement:
When the number of Property ID is increased to 5, during provisioning (using nRF Mesh Android app) process,  even though sensor_server is able to go through provisioning successfully (Note: On nRF Mesh mobile app: "<- Provisioning complete received" is shown) but it consistently failed/stopped at the "composition data get" step (Pls see nRF Mesh's  screenshot below)

I have repeatedly tried with 4 and 5 Property ID builds for several times and verified that the build with 4 Property ID is always OK in all aspects but for the build with 5 Property ID, the nRF Mesh always failed at the " -> Sending composition data get .." step. 

Some debugging info:
1. I have put in some log message in handle_composition_data_get in handle_composition_data_get() (in config_server.c) and noticed that the function runs ok all the way till the end (i.e. app_evt_send(&evt). 

2. The handle_config_default_ttl_get() is not invoked for the case of 5 Property ID

This is unclear to me the issue lies with nRF52840 firmware or with the nRF Mesh mobile app.

Pls advise what needs to be done to make the sensor_server_model capable of supporting 5 Property IDs (for 5 sensors).

Another side issue:
When the sensor_server model supports only 3 sensors (3 Property IDs and 3 descriptors), I am able to click "Get Sensor" on nRF Mesh app to get the 3 sensors info showing up (under Sensor Information section). However, when testing with sensor_server with 4 sensors (4 Property ID and 4 descriptors). Upon clicking the "Get Sensor" on nRF Mesh, the nRF Mesh app will either has no response or exit from Sensor Server model screen. 

  

 

Parents
  • Hi,

    Could you provide me with your firmware if possible? And a step-by-step procedure on how I can try reproduce this on my side.

  • Thank you for the code and the step-by-step procedure, I will try reproducing the issue and come back to you.

  • Hi Mttrinh,

    Phone 1:  Huawei Nova 3i, Android ver 9

    Phone 2: Huawei Mate 10, Android ver 10

    Tablet: Huawei MediaPad T5, Android ver 8.0.0

    New logs collected after applying the given patch: First one collected while testing with  Phone 1 (Android ver 9) while the second log collected during testing using Tablet. Both are running nRF Mesh v3.1.3.

    # SEGGER J-Link RTT Viewer V6.88a Terminal Log File
    # Compiled: 15:12:58 on Nov 18 2020
    # Logging started @ 25 Mar 2021 23:04:01
    00> <t:    1557573>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    1576599>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1651462>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    1652454>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1757178>, main.c,  657, Device identification started
    00> <t:    1757186>, mesh_gatt.c,  168, HVN data: 03010100010001000000000000
    00> <t:    1757191>, mesh_gatt.c,  219, status: 0 len: 13 usable-mtu:66 sar_type: 0 
    00> <t:    1757196>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1768970>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1940020>, main.c,  666, Device identification stopped
    00> <t:    1945930>, mesh_gatt.c,  168, HVN data: 0303272417B930D0DC143BEB431E800A11ED9557AFA4CF45951891DD90C1E7D6023437013EFB68E93E959A849EE3E320341C3237AB39BC58FB25605F6B67550F54AB
    00> <t:    1945938>, mesh_gatt.c,  219, status: 0 len: 66 usable-mtu:66 sar_type: 0 
    00> <t:    1950742>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1963615>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1963638>, mesh_gatt.c,  168, HVN data: 030558BBC1FB6917C0B5A3F5E9F63F48E46F
    00> <t:    1963644>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1963649>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1975412>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1975427>, mesh_gatt.c,  168, HVN data: 0306880DB04D7EC3061293AAF5C10E17ADAF
    00> <t:    1975432>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1975451>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1987207>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1987235>, mesh_gatt.c,  168, HVN data: 0308
    00> <t:    1987239>, mesh_gatt.c,  219, status: 0 len: 2 usable-mtu:66 sar_type: 0 
    00> <t:    1987290>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1998995>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2028497>, mesh_gatt.c,  256, conn_index_free: 0
    00> <t:    2029391>, main.c,  672, Successfully provisioned
    00> <t:    2029396>, main.c,  732, Node Address: 0x0002 
    00> <t:    2029400>, main.c,  938, Battery voltage (mV): 324, Battery level: 0%
    00> <t:    2136731>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    2136734>, proxy.c,  633, Connected
    00> <t:    2157969>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2234758>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    2235495>, proxy.c,  671, TX ready
    00> <t:    2235504>, mesh_gatt.c,  168, HVN data: 0101006FDDDC460B16A2D8000000001DFE2EF6183AF617
    00> <t:    2235509>, mesh_gatt.c,  219, status: 0 len: 23 usable-mtu:66 sar_type: 0 
    00> <t:    2235514>, proxy.c,  684, TX complete
    00> <t:    2235516>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2235787>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2240202>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2305104>, proxy.c,  676, RX
    00> <t:    2305110>, proxy.c,  607, RX GATT PDU type 0x0, len 21
    00> <t:    2305125>, access.c,  253, RX: [aop: 0x8008]
    00> <t:    2305128>, access.c,  276, RX: Msg: FF
    00> <t:    2305130>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0000  alloc? 1  addr_match? 1  key_bound? 1  opcode? 1
    00> <t:    2305137>, config_server.c,  896, composition_data_get:: 590000000000280007000000050000000200001101110C10
    00> <t:    2305141>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0002  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2305146>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1100  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2305151>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1101  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2305156>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x100C  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    3012438>, main.c,  938, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    3995478>, main.c,  938, Battery voltage (mV): 318, Battery level: 0%
    
    # Logging stopped @ 25 Mar 2021 23: 5:30
    
      

    # SEGGER J-Link RTT Viewer V6.88a Terminal Log File
    # Compiled: 15:12:58 on Nov 18 2020
    # Logging started @ 25 Mar 2021 23:07:09
    00> <t:    1668524>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    1686195>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1760485>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    1761720>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1819262>, main.c,  657, Device identification started
    00> <t:    1819270>, mesh_gatt.c,  168, HVN data: 03010100010001000000000000
    00> <t:    1819274>, mesh_gatt.c,  219, status: 0 len: 13 usable-mtu:66 sar_type: 0 
    00> <t:    1819279>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1831053>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1901836>, main.c,  666, Device identification stopped
    00> <t:    1913644>, mesh_gatt.c,  168, HVN data: 0303FDD74893FBE478F24DD0350F4CEE5C26B8F239F4639D08A9BB8923BD4E8506C67371F7C3A79C56F1C53AFC82316DBB7706320B5E35CA2F0EDCEF5B9CEF056B00
    00> <t:    1913653>, mesh_gatt.c,  219, status: 0 len: 66 usable-mtu:66 sar_type: 0 
    00> <t:    1918445>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1931329>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1931353>, mesh_gatt.c,  168, HVN data: 030501C406D0A21EDAA1BB71EB067E1820F9
    00> <t:    1931358>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1931363>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1943126>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1943141>, mesh_gatt.c,  168, HVN data: 030627E348D0220F242C041B93B69E31F964
    00> <t:    1943146>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1943165>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1954921>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1954949>, mesh_gatt.c,  168, HVN data: 0308
    00> <t:    1954953>, mesh_gatt.c,  219, status: 0 len: 2 usable-mtu:66 sar_type: 0 
    00> <t:    1955004>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1966709>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1996211>, mesh_gatt.c,  256, conn_index_free: 0
    00> <t:    1997104>, main.c,  672, Successfully provisioned
    00> <t:    1997109>, main.c,  732, Node Address: 0x0002 
    00> <t:    1997114>, main.c,  938, Battery voltage (mV): 312, Battery level: 0%
    00> <t:    2111352>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    2111355>, proxy.c,  633, Connected
    00> <t:    2129083>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2203455>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    2204192>, proxy.c,  671, TX ready
    00> <t:    2204201>, mesh_gatt.c,  168, HVN data: 0101008E75D551C0A96625000000005B4E7335886CFF50
    00> <t:    2204206>, mesh_gatt.c,  219, status: 0 len: 23 usable-mtu:66 sar_type: 0 
    00> <t:    2204211>, proxy.c,  684, TX complete
    00> <t:    2204213>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2204680>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2204690>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2274047>, proxy.c,  676, RX
    00> <t:    2274053>, proxy.c,  607, RX GATT PDU type 0x0, len 21
    00> <t:    2274068>, access.c,  253, RX: [aop: 0x8008]
    00> <t:    2274071>, access.c,  276, RX: Msg: FF
    00> <t:    2274073>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0000  alloc? 1  addr_match? 1  key_bound? 1  opcode? 1
    00> <t:    2274080>, config_server.c,  896, composition_data_get:: 590000000000280007000000050000000200001101110C10
    00> <t:    2274084>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0002  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2274089>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1100  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2274094>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1101  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2274099>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x100C  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2980152>, main.c,  938, Battery voltage (mV): 312, Battery level: 0%
    00> <t:    3963192>, main.c,  938, Battery voltage (mV): 318, Battery level: 0%
    
    # Logging stopped @ 25 Mar 2021 23: 8:59
    

    I will try to collect Android log tomorrow.

  • Hi,

    Thank you for the information and logs. We need some more logs to try narrow down the issue. Could you apply this new patch with more logs and collect the data one more time? output2.patch

    deno said:
    I will try to collect Android log tomorrow.

    That would be great :) 

  • Hi,

    Here are the RTT log and adb log taken after output2.patch applied:

    # SEGGER J-Link RTT Viewer V6.88a Terminal Log File
    # Compiled: 15:12:58 on Nov 18 2020
    # Logging started @ 26 Mar 2021 21:41:21
    00> <t:          0>, main.c, 1201, ----- WPSN Sensor Server (Relay Node) Demo -----
    00> <t:      12894>, main.c, 1013, Initializing and adding models
    00> <t:      12900>, main.c, 1020, App Sensor Setup Server Model Handle - no errs: 3
    00> <t:      12904>, main.c, 1029, App Battery Server Model Handle - no errs: 4
    00> <t:      17781>, mesh_app_utils.c,   66, Device UUID (raw): 54AF46540F2E415CB0BB4C7D1AC12488
    00> <t:      17784>, mesh_app_utils.c,   67, Device UUID : 54AF4654-0F2E-415C-B0BB-4C7D1AC12488
    00> <t:      17802>, main.c, 1308, 
    00>     ---------------------------------------------------
    00>      Button/RTT 1) To publish sensor data of temperature sensor.
    00>      Button/RTT 2) To publish present battery state value.
    00>      Button/RTT 3) Unused.
    00>      Button/RTT 4) Clear all the states to reset the node.
    00>     ---------------------------------------------------
    00> <t:    1490092>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    1507346>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1582250>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    1583242>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    1652577>, main.c,  657, Device identification started
    00> <t:    1652585>, mesh_gatt.c,  168, HVN data: 03010100010001000000000000
    00> <t:    1652590>, mesh_gatt.c,  219, status: 0 len: 13 usable-mtu:66 sar_type: 0 
    00> <t:    1652595>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1664369>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1782336>, main.c,  666, Device identification stopped
    00> <t:    1794145>, mesh_gatt.c,  168, HVN data: 03037DEAA25A7300316EDDE1C7FDEFCA4B0CDB7748884D1C97FC6470BC2D00AD5BA4CD2DF5880D5167CA73DB9D469D5A1A3D5E846024DDE22ADD0E189E9582A3DD0D
    00> <t:    1794153>, mesh_gatt.c,  219, status: 0 len: 66 usable-mtu:66 sar_type: 0 
    00> <t:    1798933>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1817728>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1817751>, mesh_gatt.c,  168, HVN data: 030545FE659528638235717B8D5C5543F60E
    00> <t:    1817756>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1817762>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1829524>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1829540>, mesh_gatt.c,  168, HVN data: 03067958D0A74C5F363F66A88336ADC1F4AD
    00> <t:    1829545>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    1829564>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1841319>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1841348>, mesh_gatt.c,  168, HVN data: 0308
    00> <t:    1841352>, mesh_gatt.c,  219, status: 0 len: 2 usable-mtu:66 sar_type: 0 
    00> <t:    1841399>, config_server.c, 3205, config_server_bind
    00> <t:    1841405>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1853108>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    1882609>, mesh_gatt.c,  256, conn_index_free: 0
    00> <t:    1883494>, main.c,  672, Successfully provisioned
    00> <t:    1883499>, main.c,  732, Node Address: 0x0002 
    00> <t:    1883504>, main.c,  938, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    1990603>, mesh_gatt.c,  241, conn_index_alloc: 0
    00> <t:    1990606>, proxy.c,  633, Connected
    00> <t:    2008600>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2083504>, mesh_gatt.c,  582, New MTU: 66
    00> <t:    2084488>, proxy.c,  671, TX ready
    00> <t:    2084498>, mesh_gatt.c,  168, HVN data: 01010069D9DFAC36B7F33200000000BD788471B6ED5649
    00> <t:    2084503>, mesh_gatt.c,  219, status: 0 len: 23 usable-mtu:66 sar_type: 0 
    00> <t:    2084509>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2084513>, proxy.c,  684, TX complete
    00> <t:    2084515>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2100745>, mesh_gatt.c,  405, Couldn't pop packet from buffer
    00> <t:    2159749>, proxy.c,  676, RX
    00> <t:    2159755>, proxy.c,  607, RX GATT PDU type 0x0, len 21
    00> <t:    2159770>, access.c,  253, RX: [aop: 0x8008]
    00> <t:    2159772>, access.c,  276, RX: Msg: FF
    00> <t:    2159775>, access.c, 1087, cmp_id: 0xFFFF mdl_id: 0x0000  alloc? 1  addr_match? 1  key_bound? 1  opcode? 1
    00> <t:    2159781>, config_server.c,  898, composition_data_get:: 590000000000280007000000050000000200001101110C10
    00> <t:    2159785>, config_server.c,  205, access_model_reply status: 4
    00> <t:    2159788>, access.c, 1087, cmp_id: 0xFFFF mdl_id: 0x0002  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2159793>, access.c, 1087, cmp_id: 0xFFFF mdl_id: 0x1100  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2159798>, access.c, 1087, cmp_id: 0xFFFF mdl_id: 0x1101  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2159803>, access.c, 1087, cmp_id: 0xFFFF mdl_id: 0x100C  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2866542>, main.c,  938, Battery voltage (mV): 312, Battery level: 0%
    00> <t:    3849582>, main.c,  938, Battery voltage (mV): 306, Battery level: 0%
    00> <t:    4832622>, main.c,  938, Battery voltage (mV): 312, Battery level: 0%
    00> <t:    5815662>, main.c,  938, Battery voltage (mV): 312, Battery level: 0%
    
    # Logging stopped @ 26 Mar 2021 21:44:27
    

    adb_logcat_w_patch2_trial2.log

  • It seems like the access layer couldn't allocate the packet using mesh_mem_alloc as it returned NRF_ERROR_NO_MEM.

    I suggest you to increase PACKET_MGR_MEMORY_POOL_SIZE.

  • Ok, I will try to increase it from 4096 to 5120 and see if it helps to solve. Thanks

Reply Children
No Data
Related