Stack overflow after GPS when integrating SMS and PDU libraries (based on asset tracker v2)

[danimalia]

Hello 

I have this firmware running in C:\Users\danie\ncs\v1.5.1\nrf\applications\tracker  on the nRF9160-DK, nRF9160 SICA B1 is the marking on the chip

Modem FW is 1.2.3: 

See the attached log, it overflows every time there is a GPS lock. Please can you give us some guidance. 

Kind regards

Dan

edit: I updated modem firmware to 1.3.0 but issue is still present. 

Fullscreen 2860.2021-05-20T00_54_05.457Z-log.txt Download

2021-05-20T00:54:08.225Z INFO Application data folder: C:\Users\danie\AppData\Roaming\nrfconnect\pc-nrfconnect-linkmonitor
2021-05-20T00:54:08.278Z DEBUG App pc-nrfconnect-toolchain-manager v0.9.1 official
2021-05-20T00:54:08.278Z DEBUG App path: C:\Users\danie\.nrfconnect-apps\node_modules\pc-nrfconnect-toolchain-manager
2021-05-20T00:54:08.278Z DEBUG nRFConnect 3.6.1 is supported by the app (^3.6.0)
2021-05-20T00:54:08.278Z DEBUG nRFConnect path: C:\Users\danie\AppData\Local\Programs\nrfconnect\resources\app.asar
2021-05-20T00:54:08.279Z DEBUG HomeDir: C:\Users\danie
2021-05-20T00:54:08.279Z DEBUG TmpDir: C:\Users\danie\AppData\Local\Temp
2021-05-20T00:59:50.851Z INFO Modem port is opened
2021-05-20T00:59:54.117Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-05-20T00:59:54.147Z DEBUG modem << I: Starting bootloader
2021-05-20T00:59:54.150Z DEBUG modem << I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-05-20T00:59:54.152Z DEBUG modem << I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-05-20T00:59:54.155Z DEBUG modem << I: Boot source: none
2021-05-20T00:59:54.157Z DEBUG modem << I: Swap type: none
2021-05-20T00:59:54.202Z DEBUG modem << I: Bootloader chainload address offset: 0x10000
2021-05-20T00:59:54.210Z DEBUG modem << I: Jumping to the first image slot
2021-05-20T00:59:56.329Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-05-20T00:59:56.335Z DEBUG modem << [00:00:00.206,420] [0m<inf> event_manager: APP_EVT_START[0m
2021-05-20T00:59:56.355Z DEBUG modem << [00:00:00.226,348] [0m<inf> event_manager: DATA_EVT_CONFIG_INIT[0m
2021-05-20T00:59:56.362Z DEBUG modem << [00:00:00.232,727] [0m<inf> sms: SMS client successfully registered[0m
2021-05-20T00:59:56.368Z DEBUG modem << [00:00:00.239,135] [0m<inf> app_module: Device mode: Passive[0m
2021-05-20T00:59:56.377Z DEBUG modem << [00:00:00.244,934] [0m<inf> app_module: Start movement timeout: 30 seconds interval[0m
2021-05-20T00:59:56.446Z DEBUG modem << [00:00:00.316,711] [0m<inf> event_manager: MODEM_EVT_LTE_CONNECTING[0m
2021-05-20T00:59:57.988Z DEBUG modem << [00:00:01.859,069] [0m<inf> event_manager: MODEM_EVT_LTE_DISCONNECTED[0m
2021-05-20T00:59:57.996Z DEBUG modem << [00:00:01.865,875] [0m<inf> event_manager: MODEM_EVT_LTE_CELL_UPDATE[0m
2021-05-20T00:59:59.179Z DEBUG modem << [00:00:03.049,865] [0m<inf> event_manager: MODEM_EVT_LTE_CONNECTED[0m
2021-05-20T00:59:59.186Z DEBUG modem << [00:00:03.056,427] [0m<inf> event_manager: MODEM_EVT_LTE_PSM_UPDATE[0m
2021-05-20T00:59:59.194Z DEBUG modem << [00:00:03.063,110] [1;33m<wrn> cloud_module: Cloud connection establishment in progress[0m
2021-05-20T00:59:59.205Z DEBUG modem << [00:00:03.071,228] [1;33m<wrn> cloud_module: New connection attempt in 32 seconds if not successful[0m
2021-05-20T00:59:59.210Z DEBUG modem << [00:00:03.080,566] [0m<inf> event_manager: CLOUD_EVT_CONNECTING[0m
2021-05-20T01:00:01.948Z DEBUG modem << [00:00:05.819,488] [0m<inf> event_manager: CLOUD_EVT_CONNECTED[0m
2021-05-20T01:00:02.372Z DEBUG modem << [00:00:06.243,103] [0m<inf> event_manager: DATA_EVT_DATE_TIME_OBTAINED[0m
2021-05-20T01:00:02.382Z DEBUG modem << [00:00:06.250,061] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS, MOD_STAT)[0m
2021-05-20T01:00:02.395Z DEBUG modem << [00:00:06.266,510] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:00:02.405Z DEBUG modem << [00:00:06.272,399] [0m<inf> event_manager: GPS_EVT_AGPS_NEEDED[0m
2021-05-20T01:00:02.408Z DEBUG modem << [00:00:06.279,022] [0m<inf> agps: SUPL is initialized[0m
2021-05-20T01:00:02.452Z DEBUG modem << [00:00:06.322,723] [0m<inf> event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY[0m
2021-05-20T01:00:02.578Z DEBUG modem << [00:00:06.448,486] [0m<inf> event_manager: CLOUD_EVT_CONFIG_RECEIVED[0m
2021-05-20T01:00:02.585Z DEBUG modem << [00:00:06.455,810] [0m<inf> event_manager: DATA_EVT_CONFIG_READY[0m
2021-05-20T01:00:02.591Z DEBUG modem << [00:00:06.462,097] [0m<inf> app_module: Device mode: Passive[0m
2021-05-20T01:00:02.602Z DEBUG modem << [00:00:06.467,864] [0m<inf> app_module: Start movement timeout: 30 seconds interval[0m
2021-05-20T01:00:02.607Z DEBUG modem << [00:00:06.475,708] [1;33m<wrn> data_module: No change in current device configuration[0m
2021-05-20T01:00:02.712Z DEBUG modem << [00:00:06.583,709] [0m<inf> agps: Starting SUPL session[0m
2021-05-20T01:00:05.288Z DEBUG modem << [00:00:09.158,935] [0m<inf> agps: SUPL session finished successfully[0m
2021-05-20T01:00:24.063Z DEBUG modem << [00:00:27.935,089] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:00:24.070Z DEBUG modem << [00:00:27.941,345] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:00:24.076Z DEBUG modem << [00:00:27.947,814] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:00:24.088Z DEBUG modem << [00:00:27.959,625] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:00:24.130Z DEBUG modem << [00:00:28.002,532] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:00:32.603Z DEBUG modem << [00:00:36.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:00:32.612Z DEBUG modem << [00:00:36.482,177] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:00:32.647Z DEBUG modem << [00:00:36.520,172] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:00:34.722Z DEBUG modem << [00:00:38.595,123] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:00:34.729Z DEBUG modem << [00:00:38.601,379] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:00:34.735Z DEBUG modem << [00:00:38.607,849] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:00:34.750Z DEBUG modem << [00:00:38.616,973] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:00:34.786Z DEBUG modem << [00:00:38.659,820] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:01:02.601Z DEBUG modem << [00:01:06.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:01:02.609Z DEBUG modem << [00:01:06.482,177] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:01:02.675Z DEBUG modem << [00:01:06.550,170] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:01:03.761Z DEBUG modem << [00:01:07.636,718] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:01:03.768Z DEBUG modem << [00:01:07.643,005] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:01:03.774Z DEBUG modem << [00:01:07.649,475] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:01:03.784Z DEBUG modem << [00:01:07.658,752] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:01:03.827Z DEBUG modem << [00:01:07.701,599] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:01:32.599Z DEBUG modem << [00:01:36.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:01:32.607Z DEBUG modem << [00:01:36.482,177] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:01:32.673Z DEBUG modem << [00:01:36.550,537] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:01:33.764Z DEBUG modem << [00:01:37.641,448] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:01:33.773Z DEBUG modem << [00:01:37.647,705] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:01:33.780Z DEBUG modem << [00:01:37.654,174] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:01:33.786Z DEBUG modem << [00:01:37.663,452] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:01:33.829Z DEBUG modem << [00:01:37.706,298] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:02:02.596Z DEBUG modem << [00:02:06.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:02:02.605Z DEBUG modem << [00:02:06.482,177] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:02:02.670Z DEBUG modem << [00:02:06.550,201] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:02:03.758Z DEBUG modem << [00:02:07.637,512] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:02:03.767Z DEBUG modem << [00:02:07.643,768] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:02:03.770Z DEBUG modem << [00:02:07.650,238] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:02:03.783Z DEBUG modem << [00:02:07.659,515] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:02:03.822Z DEBUG modem << [00:02:07.702,331] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:02:32.594Z DEBUG modem << [00:02:36.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:02:32.604Z DEBUG modem << [00:02:36.482,147] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:02:32.668Z DEBUG modem << [00:02:36.550,170] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:02:33.749Z DEBUG modem << [00:02:37.630,981] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:02:33.758Z DEBUG modem << [00:02:37.637,237] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:02:33.762Z DEBUG modem << [00:02:37.643,737] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:02:33.771Z DEBUG modem << [00:02:37.652,984] [0m<inf> event_manager: DATA_EVT_DATA_SEND[0m
2021-05-20T01:02:33.814Z DEBUG modem << [00:02:37.695,800] [0m<inf> event_manager: CLOUD_EVT_DATA_ACK[0m
2021-05-20T01:03:02.591Z DEBUG modem << [00:03:06.475,799] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:03:02.600Z DEBUG modem << [00:03:06.482,177] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS)[0m
2021-05-20T01:03:02.666Z DEBUG modem << [00:03:06.550,567] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:03:03.756Z DEBUG modem << [00:03:07.640,533] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:03:03.764Z DEBUG modem << [00:03:07.646,820] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:03:03.769Z DEBUG modem << [00:03:07.653,289] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:04:14.774Z DEBUG modem << [00:04:18.663,818] [1;31m<err> os: ***** USAGE FAULT *****[0m
2021-05-20T01:04:14.781Z DEBUG modem << [00:04:18.669,403] [1;31m<err> os:   Stack overflow (context area not valid)[0m
2021-05-20T01:04:14.790Z DEBUG modem << [00:04:18.676,635] [1;31m<err> os: r0/a1:  0x00043b10  r1/a2:  0x81000200  r2/a3:  0x33f6e7fe[0m
2021-05-20T01:04:14.799Z DEBUG modem << [00:04:18.685,333] [1;31m<err> os: r3/a4:  0x21483084 r12/ip:  0x8db7fbb9 r14/lr:  0x68188137[0m
2021-05-20T01:04:14.804Z DEBUG modem << [00:04:18.694,061] [1;31m<err> os:  xpsr:  0x291ea000[0m
2021-05-20T01:04:14.816Z DEBUG modem << [00:04:18.699,279] [1;31m<err> os: s[ 0]:  0x00000000  s[ 1]:  0x00000000  s[ 2]:  0x00000000  s[ 3]:  0x00000000[0m
2021-05-20T01:04:14.830Z DEBUG modem << [00:04:18.709,716] [1;31m<err> os: s[ 4]:  0x00000000  s[ 5]:  0x00000002  s[ 6]:  0x00000000  s[ 7]:  0x00000000[0m
2021-05-20T01:04:14.836Z DEBUG modem << [00:04:18.720,184] [1;31m<err> os: s[ 8]:  0x00000000  s[ 9]:  0x00000000  s[10]:  0x00000000  s[11]:  0x00000000[0m
2021-05-20T01:04:14.849Z DEBUG modem << [00:04:18.730,621] [1;31m<err> os: s[12]:  0x00000000  s[13]:  0x00000000  s[14]:  0x00000000  s[15]:  0x00000000[0m
2021-05-20T01:04:14.852Z DEBUG modem << [00:04:18.741,088] [1;31m<err> os: fpscr:  0x2002b9e0[0m
2021-05-20T01:04:14.865Z DEBUG modem << [00:04:18.746,307] [1;31m<err> os: Faulting instruction address (r15/pc): 0x3f5fa9f9[0m
2021-05-20T01:04:14.868Z DEBUG modem << [00:04:18.754,241] [1;31m<err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0[0m
2021-05-20T01:04:14.880Z DEBUG modem << [00:04:18.762,176] [1;31m<err> os: Current thread: 0x20017150 (unknown)[0m
2021-05-20T01:04:14.882Z DEBUG modem << [00:04:18.769,256] [0m<inf> event_manager: UTIL_EVT_SHUTDOWN_REQUEST[0m
2021-05-20T01:04:14.887Z DEBUG modem << [00:04:18.776,062] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:04:14.899Z DEBUG modem << [00:04:18.782,287] [0m<inf> event_manager: APP_EVT_DATA_GET_ALL[0m
2021-05-20T01:04:14.901Z DEBUG modem << [00:04:18.788,482] [0m<inf> event_manager: UI_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:14.906Z DEBUG modem << [00:04:18.794,677] [0m<inf> event_manager: GPS_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:14.917Z DEBUG modem << [00:04:18.801,116] [0m<inf> event_manager: APP_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:14.919Z DEBUG modem << [00:04:18.807,647] [0m<inf> event_manager: CLOUD_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:14.931Z DEBUG modem << [00:04:18.814,331] [0m<inf> event_manager: SENSOR_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:15.765Z DEBUG modem << [00:04:19.654,724] [0m<inf> event_manager: CLOUD_EVT_DISCONNECTED[0m
2021-05-20T01:04:15.780Z DEBUG modem << [00:04:19.661,956] [0m<inf> event_manager: MODEM_EVT_LTE_DISCONNECTED[0m
2021-05-20T01:04:15.783Z DEBUG modem << [00:04:19.668,548] [1;33m<wrn> modules_common: data: Message could not be enqueued, error code: -35[0m
2021-05-20T01:04:15.797Z DEBUG modem << [00:04:19.677,764] [1;31m<err> data_module: Message could not be enqueued[0m
2021-05-20T01:04:15.799Z DEBUG modem << [00:04:19.684,875] [0m<inf> event_manager: DATA_EVT_ERROR - Error code -35[0m
2021-05-20T01:04:18.602Z DEBUG modem << [00:04:22.492,095] [0m<inf> event_manager: MODEM_EVT_SHUTDOWN_READY[0m
2021-05-20T01:04:35.094Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-05-20T01:04:35.103Z DEBUG modem << I: Starting bootloader
2021-05-20T01:04:35.105Z DEBUG modem << I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-05-20T01:04:35.110Z DEBUG modem << I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-05-20T01:04:35.112Z DEBUG modem << I: Boot source: none
2021-05-20T01:04:35.114Z DEBUG modem << I: Swap type: none
2021-05-20T01:04:35.180Z DEBUG modem << I: Bootloader chainload address offset: 0x10000
2021-05-20T01:04:35.188Z DEBUG modem << I: Jumping to the first image slot
2021-05-20T01:04:35.569Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-05-20T01:04:35.578Z DEBUG modem << [00:00:00.206,481] [0m<inf> event_manager: APP_EVT_START[0m
2021-05-20T01:04:35.602Z DEBUG modem << [00:00:00.232,482] [0m<inf> event_manager: DATA_EVT_CONFIG_INIT[0m
2021-05-20T01:04:35.609Z DEBUG modem << [00:00:00.238,922] [0m<inf> sms: SMS client successfully registered[0m
2021-05-20T01:04:35.614Z DEBUG modem << [00:00:00.245,330] [0m<inf> app_module: Device mode: Passive[0m
2021-05-20T01:04:35.624Z DEBUG modem << [00:00:00.251,159] [0m<inf> app_module: Start movement timeout: 30 seconds interval[0m
2021-05-20T01:04:35.691Z DEBUG modem << [00:00:00.322,021] [0m<inf> event_manager: MODEM_EVT_LTE_CONNECTING[0m
2021-05-20T01:04:37.022Z DEBUG modem << [00:00:01.652,069] [0m<inf> event_manager: MODEM_EVT_LTE_DISCONNECTED[0m
2021-05-20T01:04:37.031Z DEBUG modem << [00:00:01.658,905] [0m<inf> event_manager: MODEM_EVT_LTE_CELL_UPDATE[0m
2021-05-20T01:04:37.893Z DEBUG modem << [00:00:02.523,620] [0m<inf> event_manager: MODEM_EVT_LTE_CONNECTED[0m
2021-05-20T01:04:37.901Z DEBUG modem << [00:00:02.530,212] [0m<inf> event_manager: MODEM_EVT_LTE_PSM_UPDATE[0m
2021-05-20T01:04:37.909Z DEBUG modem << [00:00:02.536,895] [1;33m<wrn> cloud_module: Cloud connection establishment in progress[0m
2021-05-20T01:04:37.922Z DEBUG modem << [00:00:02.545,013] [1;33m<wrn> cloud_module: New connection attempt in 32 seconds if not successful[0m
2021-05-20T01:04:37.925Z DEBUG modem << [00:00:02.554,351] [0m<inf> event_manager: CLOUD_EVT_CONNECTING[0m
2021-05-20T01:04:40.589Z DEBUG modem << [00:00:05.220,520] [0m<inf> event_manager: CLOUD_EVT_CONNECTED[0m
2021-05-20T01:04:40.849Z DEBUG modem << [00:00:05.481,445] [0m<inf> app_module: Sms received:  -> [0m
2021-05-20T01:04:41.097Z DEBUG modem << [00:00:05.727,020] [0m<inf> event_manager: DATA_EVT_DATE_TIME_OBTAINED[0m
2021-05-20T01:04:41.107Z DEBUG modem << [00:00:05.733,978] [0m<inf> event_manager: APP_EVT_DATA_GET - Requested data types (GNSS, MOD_STAT)[0m
2021-05-20T01:04:41.118Z DEBUG modem << [00:00:05.749,603] [0m<inf> event_manager: GPS_EVT_ACTIVE[0m
2021-05-20T01:04:41.124Z DEBUG modem << [00:00:05.755,493] [0m<inf> event_manager: GPS_EVT_AGPS_NEEDED[0m
2021-05-20T01:04:41.136Z DEBUG modem << [00:00:05.762,207] [0m<inf> agps: SUPL is initialized[0m
2021-05-20T01:04:41.177Z DEBUG modem << [00:00:05.806,793] [0m<inf> event_manager: MODEM_EVT_MODEM_STATIC_DATA_READY[0m
2021-05-20T01:04:41.262Z DEBUG modem << [00:00:05.892,639] [0m<inf> event_manager: CLOUD_EVT_CONFIG_RECEIVED[0m
2021-05-20T01:04:41.270Z DEBUG modem << [00:00:05.899,963] [0m<inf> event_manager: DATA_EVT_CONFIG_READY[0m
2021-05-20T01:04:41.275Z DEBUG modem << [00:00:05.906,250] [0m<inf> app_module: Device mode: Passive[0m
2021-05-20T01:04:41.285Z DEBUG modem << [00:00:05.912,017] [0m<inf> app_module: Start movement timeout: 30 seconds interval[0m
2021-05-20T01:04:41.291Z DEBUG modem << [00:00:05.920,104] [1;33m<wrn> data_module: No change in current device configuration[0m
2021-05-20T01:04:41.411Z DEBUG modem << [00:00:06.041,198] [0m<inf> app_module: Sms received: 19499104550 -> Test[0m
2021-05-20T01:04:41.425Z DEBUG modem << [00:00:06.056,640] [0m<inf> agps: Starting SUPL session[0m
2021-05-20T01:04:43.848Z DEBUG modem << [00:00:08.478,881] [0m<inf> agps: SUPL session finished successfully[0m
2021-05-20T01:05:00.626Z DEBUG modem << [00:00:25.258,605] [0m<inf> event_manager: GPS_EVT_DATA_READY[0m
2021-05-20T01:05:00.637Z DEBUG modem << [00:00:25.264,862] [0m<inf> event_manager: DATA_EVT_DATA_READY[0m
2021-05-20T01:05:00.640Z DEBUG modem << [00:00:25.271,423] [0m<inf> event_manager: GPS_EVT_INACTIVE[0m
2021-05-20T01:05:00.648Z DEBUG modem << [00:00:25.280,975] [1;31m<err> os: ***** USAGE FAULT *****[0m
2021-05-20T01:05:00.663Z DEBUG modem << [00:00:25.286,560] [1;31m<err> os:   Stack overflow (context area not valid)[0m
2021-05-20T01:05:00.665Z DEBUG modem << [00:00:25.293,823] [1;31m<err> os: r0/a1:  0x00043b10  r1/a2:  0x81000200  r2/a3:  0xe0000000[0m
2021-05-20T01:05:00.678Z DEBUG modem << [00:00:25.302,520] [1;31m<err> os: r3/a4:  0x3fb976b4 r12/ip:  0x00000000 r14/lr:  0x00000000[0m
2021-05-20T01:05:00.679Z DEBUG modem << [00:00:25.311,218] [1;31m<err> os:  xpsr:  0x00000000[0m
2021-05-20T01:05:00.696Z DEBUG modem << [00:00:25.316,467] [1;31m<err> os: s[ 0]:  0x00000000  s[ 1]:  0x00000000  s[ 2]:  0x00000000  s[ 3]:  0x00000000[0m
2021-05-20T01:05:00.698Z DEBUG modem << [00:00:25.326,904] [1;31m<err> os: s[ 4]:  0x00000000  s[ 5]:  0x00000000  s[ 6]:  0x00000000  s[ 7]:  0x00000000[0m
2021-05-20T01:05:00.714Z DEBUG modem << [00:00:25.337,371] [1;31m<err> os: s[ 8]:  0x00000000  s[ 9]:  0x00000000  s[10]:  0x00000000  s[11]:  0x00000000[0m
2021-05-20T01:05:00.720Z DEBUG modem << [00:00:25.347,839] [1;31m<err> os: s[12]:  0x00000000  s[13]:  0x00000000  s[14]:  0x00000000  s[15]:  0x00000000[0m
2021-05-20T01:05:00.735Z DEBUG modem << [00:00:25.358,276] [1;31m<err> os: fpscr:  0x2002b9e0[0m
2021-05-20T01:05:00.736Z DEBUG modem << [00:00:25.363,525] [1;31m<err> os: Faulting instruction address (r15/pc): 0x00000000[0m
2021-05-20T01:05:00.750Z DEBUG modem << [00:00:25.371,459] [1;31m<err> os: >>> ZEPHYR FATAL ERROR 2: Stack overflow on CPU 0[0m
2021-05-20T01:05:00.752Z DEBUG modem << [00:00:25.379,364] [1;31m<err> os: Current thread: 0x20017150 (unknown)[0m
2021-05-20T01:05:00.764Z DEBUG modem << [00:00:25.386,291] [0m<inf> event_manager: UTIL_EVT_SHUTDOWN_REQUEST[0m
2021-05-20T01:05:00.766Z DEBUG modem << [00:00:25.393,005] [0m<inf> event_manager: UI_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:00.767Z DEBUG modem << [00:00:25.399,230] [0m<inf> event_manager: GPS_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:00.784Z DEBUG modem << [00:00:25.405,670] [0m<inf> event_manager: APP_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:00.785Z DEBUG modem << [00:00:25.412,170] [0m<inf> event_manager: CLOUD_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:00.799Z DEBUG modem << [00:00:25.418,853] [0m<inf> event_manager: SENSOR_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:05.882Z DEBUG modem << [00:00:30.513,580] [0m<inf> event_manager: CLOUD_EVT_DISCONNECTED[0m
2021-05-20T01:05:05.888Z DEBUG modem << [00:00:30.520,507] [0m<inf> event_manager: MODEM_EVT_LTE_DISCONNECTED[0m
2021-05-20T01:05:06.037Z DEBUG modem << [00:00:30.669,769] [0m<inf> event_manager: MODEM_EVT_SHUTDOWN_READY[0m
2021-05-20T01:05:09.627Z INFO Modem port is closed

[Didrik Rokhaug]

I haven't had time to test your application yet. Is there anything in paraticular you want me to try?

The log shows that the stack overflow comes from the data_module thread.

You can set it's stack size with CONFIG_DATA_THREAD_STACK_SIZE. The default is 2048.

The data_module also has a lot of other buffers. To see what options exists for controlling their sizes, you can take a look at asset_tracker_v2/src/modules/Kconfig.data_module.

[Aidanv]

Hi Didrik

I'm working with Dan on this project. Thank you for assisting us with this issue.

The problem is that we simply add SMS functionality and PDU decoding to the original Asset Tracker v2 example. This is causing stack overflows. The fact that every time Dan has increased the stack size has merely delayed the issue implies a deeper issue.

It's not clear how our code could cause this issue as the  functions we have added are not even called at this point (only when an SMS is received). The overflow occurs during normal out-of-the-box functionality of asset tracker v2.

We're new to Zephyr, and we're just trying make what should be a simple modification to the example. Please can you review the small amount of code that we've added to see if we have done something obviously wrong?

Thank you

Aidan 

[Didrik Rokhaug]

Hello, and sorry for the late answer.

Unfortunately, it doesn't look like your application is attached to the ticket any longer.

Could you re-upload it, or send it to me in a direct message, so I can take a look at it?

Best regards,

Didrik

[Aidanv]

Hi Didrik,

I sent you the application in a private message. 

Thanks

Aidan

[Didrik Rokhaug]

Thanks.

I am able to reproduce the crash, though it seems to be dependent on the GPS. If the device doesn't get GPS fixes, I don't see the crashes.

Other than that I haven't been able to make much more progress in identifying the cause of the crash, but I will keep investigating.

[Aidanv]

Thank you Didrik. That is correct. It  only occurs on GPS lock.
If I recall correctly, even if we do not reference our added source code (sms and pdu) it still crashes.

[Didrik Rokhaug]

Quick update: I am able to reproduce the crash with just changes to prj.conf.

My current suspect is CONFIG_NEWLIB_LIBC_FLOAT_SCANF, but I'll keep working on this tomorrow.

[Didrik Rokhaug]

Yes, it looks like CONFIG_NEWLIB_LIBC_FLOAT_SCANF is the culprit.

Why did you add it? It doesn't look like you are using scanf in your project.

If I remove the option, I am no longer able to reproduce the crash in your code.

[Aidanv]

Hi Didrik.

Thank you, it seems to be working on Dan's side now (harder for me to test on this side due to my location).

We initially were going to use scanf for the binary to hex conversion. I know that we did test without the CONFIG_NEWLIB_LIBC_FLOAT_SCANF but it's possible that there were issues with the build not being cleaned first or something. 

What would we do if we did need to use scanf? Slightly concerning that such a simple change could cause such an obscure problem.

[Didrik Rokhaug]

As long as you do not need scanf for floats, you should be fine without the option.

Though I am not sure what your best option would be if you need float support.