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.

  • Thanks for your help. Looking forward to your update.

  • Hi, 

    Regarding your main issue could you try with the latest version of nRF Mesh app for Android(v3.1.3)? You can find it here

    Could also try with other phones(iOS/Android) if you any lying around?

    Does it make any difference?

    If you still see the issue can you collect more logs? Try adding LOG_SRC_BEARER and increase log level to LOG_LEVEL_DBG3 in __LOG_INIT macro:

    __LOG_INIT(LOG_SRC_APP | LOG_SRC_ACCESS | LOG_SRC_FRIEND | LOG_SRC_BEARER, LOG_LEVEL_DBG3, LOG_CALLBACK_DEFAULT);

  • Hi Mttrinh,

    I've tried with nRF Mesh app for Android (v3.1.3) on a phone and a tablet. The same problem persists, stuck in "Sending composition data get ..." step. Log files (per your request) taken for both trials.  

    # SEGGER J-Link RTT Viewer V6.88a Terminal Log File
    # Compiled: 15:12:58 on Nov 18 2020
    # Logging started @ 24 Mar 2021 23:12:19
    00> <t:    2025853>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2101740>, mesh_gatt.c,  576, New MTU: 66
    00> <t:    2102975>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2148721>, main.c,  628, Device identification started
    00> <t:    2148728>, mesh_gatt.c,  168, HVN data: 03010100010001000000000000
    00> <t:    2148733>, mesh_gatt.c,  219, status: 0 len: 13 usable-mtu:66 sar_type: 0 
    00> <t:    2349256>, main.c,  637, Device identification stopped
    00> <t:    2361065>, mesh_gatt.c,  168, HVN data: 030346F5DB81FBFD0867622F67915BC6982BD072B5F2DF799A9CA40FD18ACD87B9BDFB4C3FC83604400DC54A58A8435D3FC612543011B282ACBD65756F10D0BA192F
    00> <t:    2361073>, mesh_gatt.c,  219, status: 0 len: 66 usable-mtu:66 sar_type: 0 
    00> <t:    2372872>, mesh_gatt.c,  168, HVN data: 03058B82747841DE7A1DEDF3F4C12D285A03
    00> <t:    2372877>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    2384661>, mesh_gatt.c,  168, HVN data: 030615F6F8F05937A2543F4B7F4FD6FE9D77
    00> <t:    2384666>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    2402370>, mesh_gatt.c,  168, HVN data: 0308
    00> <t:    2402374>, mesh_gatt.c,  219, status: 0 len: 2 usable-mtu:66 sar_type: 0 
    00> <t:    2444506>, main.c,  643, Successfully provisioned
    00> <t:    2444511>, main.c,  689, Node Address: 0x0003 
    00> <t:    2444516>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    2531604>, proxy.c,  632, Connected
    00> <t:    2549594>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2625440>, mesh_gatt.c,  576, New MTU: 66
    00> <t:    2626184>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2630642>, proxy.c,  670, TX ready
    00> <t:    2630650>, mesh_gatt.c,  168, HVN data: 010100871854905F4047130000000070A5CB9D6762423E
    00> <t:    2630655>, mesh_gatt.c,  219, status: 0 len: 23 usable-mtu:66 sar_type: 0 
    00> <t:    2630660>, proxy.c,  683, TX complete
    00> <t:    2707337>, proxy.c,  675, RX
    00> <t:    2707343>, proxy.c,  606, RX GATT PDU type 0x0, len 21
    00> <t:    2707358>, access.c,  253, RX: [aop: 0x8008]
    00> <t:    2707360>, access.c,  276, RX: Msg: FF
    00> <t:    2707363>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0000  alloc? 1  addr_match? 1  key_bound? 1  opcode? 1
    00> <t:    2707368>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0002  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2707373>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1100  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2707378>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1101  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2707383>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x100C  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    3427554>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    4410594>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    5393634>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    6376674>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    
    # Logging stopped @ 24 Mar 2021 23:14:37
    
     

    # SEGGER J-Link RTT Viewer V6.88a Terminal Log File
    # Compiled: 15:12:58 on Nov 18 2020
    # Logging started @ 24 Mar 2021 23:31:35
    00> <t:    2071456>, main.c,  628, Device identification started
    00> <t:    2071464>, mesh_gatt.c,  168, HVN data: 03010100010001000000000000
    00> <t:    2071469>, mesh_gatt.c,  219, status: 0 len: 13 usable-mtu:66 sar_type: 0 
    00> <t:    2154030>, main.c,  637, Device identification stopped
    00> <t:    2165839>, mesh_gatt.c,  168, HVN data: 0303D0ACB653F183732545B3D6589E52FE76ACD3BE79726277794B3CE0DC796F6CD04BCBC11AE138D3253B8E10843693FC726E71EB298FA49E889A42AE8760CA50A9
    00> <t:    2165847>, mesh_gatt.c,  219, status: 0 len: 66 usable-mtu:66 sar_type: 0 
    00> <t:    2183544>, mesh_gatt.c,  168, HVN data: 03055EF62DA1976CB144F13ED1C12BC0E260
    00> <t:    2183549>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    2195333>, mesh_gatt.c,  168, HVN data: 03065D4917492E3088DBE5896643B09DDB5B
    00> <t:    2195338>, mesh_gatt.c,  219, status: 0 len: 18 usable-mtu:66 sar_type: 0 
    00> <t:    2207144>, mesh_gatt.c,  168, HVN data: 0308
    00> <t:    2207148>, mesh_gatt.c,  219, status: 0 len: 2 usable-mtu:66 sar_type: 0 
    00> <t:    2249292>, main.c,  643, Successfully provisioned
    00> <t:    2249296>, main.c,  689, Node Address: 0x0002 
    00> <t:    2249301>, main.c,  895, Battery voltage (mV): 312, Battery level: 0%
    00> <t:    2337269>, proxy.c,  632, Connected
    00> <t:    2355191>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2429968>, mesh_gatt.c,  576, New MTU: 66
    00> <t:    2430705>, proxy.c,  670, TX ready
    00> <t:    2430714>, mesh_gatt.c,  168, HVN data: 010100C8DBFFF775E03C1500000000CDD2EA78F07F87A0
    00> <t:    2430719>, mesh_gatt.c,  219, status: 0 len: 23 usable-mtu:66 sar_type: 0 
    00> <t:    2430724>, proxy.c,  683, TX complete
    00> <t:    2430997>, ble_softdevice_support.c,  104, Successfully updated connection parameters
    00> <t:    2500315>, proxy.c,  675, RX
    00> <t:    2500320>, proxy.c,  606, RX GATT PDU type 0x0, len 21
    00> <t:    2500335>, access.c,  253, RX: [aop: 0x8008]
    00> <t:    2500338>, access.c,  276, RX: Msg: FF
    00> <t:    2500340>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0000  alloc? 1  addr_match? 1  key_bound? 1  opcode? 1
    00> <t:    2500346>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x0002  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2500351>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1100  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2500356>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x1101  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    2500360>, access.c, 1072, cmp_id: 0xFFFF mdl_id: 0x100C  alloc? 1  addr_match? 1  key_bound? 0  opcode? 0
    00> <t:    3232339>, main.c,  895, Battery voltage (mV): 318, Battery level: 0%
    00> <t:    4215379>, main.c,  895, Battery voltage (mV): 306, Battery level: 0%
    00> <t:    5198419>, main.c,  895, Battery voltage (mV): 312, Battery level: 0%
    
    # Logging stopped @ 24 Mar 2021 23:33:20
    

  • Hi,

    Can you collect the logs from the board one more time with the following patch applied?

    Can you also collect Android logs using adb tool (command: adb logcat)?

    And which phone and tablet did you use, and which android version are they running?

    output.patch

  • 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.

Reply
  • 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.

Children
  • 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

  • Hi,

    Question: The warning regarding the max size of packet manager memory pool does not seem to reflect the current values used. Pls see text highlighted in red below.

    Can you advise what value of PACKET_MGR_MEMORY_POOL_SIZE should I use?

    In mesh\core\api\nrf_mesh_config_core.h: 

    /**
    * Size of the packet manager memory pool in bytes.
    * @warning The value of the memory pool cannot currently exceed the value of
    * PACKET_MGR_PACKET_MAXLEN, due to the current design of the memory manager.
    */
    #ifndef PACKET_MGR_MEMORY_POOL_SIZE
    #define PACKET_MGR_MEMORY_POOL_SIZE 4096
    #endif

    In mesh\core\include\packet_mgr.h

    /** Maximum length of the packets that can be allocated. */
    #define PACKET_MGR_PACKET_MAXLEN    (NRF_MESH_SEG_PAYLOAD_SIZE_MAX)

    In mesh\core\api\nrf_mesh_defines.h

    /** Maximum possible segmented payload size (octets). */
    #define NRF_MESH_SEG_PAYLOAD_SIZE_MAX (380)

Related