Application core dumps when connecting to mdash

#1

I have written a small application that works reliably until I assign a mdash token. About 7 times out of 10, as soon as the application talks to mdash it core dumps (right after I manually add the token using the call pasted below). The application periodically prints out the free RAM and there is no indication of memory starvation. I have run several backtraces and most end in one of the Mongoose libraries.

I have tried this both as c and cpp, and with different size fs_ext partitions.

If someone could tell me if I did something wrong that would be great, but I wanted to check here before I opened an issue on git. I’ll paste the relevant files below, thanks.

Call to set mdash token (token edited)

mos config-set dash.enable=true dash.token=dOS0j99ABCDEFGE4B3mLxxx

mos.yml

author: mongoose-os
description: A Mongoose OS app skeleton
version: 1.0

libs_version: ${mos.version}
modules_version: ${mos.version}
mongoose_os_version: ${mos.version}

# Optional. List of tags for online search.
tags:
  - c

# List of files / directories with C sources. No slashes at the end of dir names.
sources:
  - src

# List of dirs. Files from these dirs will be copied to the device filesystem
filesystem:
  - fs

build_vars:
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_4MB=}
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y CONFIG_ESPTOOLPY_FLASHSIZE="16MB"}
  ESP_IDF_EXTRA_PARTITION: fs_ext,data,spiffs,,12288K

config_schema:
- ["fstab.fs0.dev", "fs_ext"]
- ["fstab.fs0.type", "LFS"]
- ["fstab.fs0.opts", '{"bs": 4096}']
- ["fstab.fs0.path", "/data"]
- ["fstab.fs0.create", true]

- ["wifi.sta.enable", true]
- ["wifi.sta.ssid", "Jim LAN"]
- ["wifi.sta.pass", "password"]

libs:
  - origin: https://github.com/mongoose-os-libs/ca-bundle
  - origin: https://github.com/mongoose-os-libs/rpc-service-config
  - origin: https://github.com/mongoose-os-libs/rpc-service-fs
  - origin: https://github.com/mongoose-os-libs/rpc-uart
  - origin: https://github.com/mongoose-os-libs/dash
  - origin: https://github.com/mongoose-os-libs/rpc-service-ota
  - origin: https://github.com/mongoose-os-libs/wifi

  # Added for file system
  - origin: https://github.com/mongoose-os-libs/fstab
  - origin: https://github.com/mongoose-os-libs/vfs-fs-lfs

# Used by the mos tool to catch mos binaries incompatible with this file format
manifest_version: 2017-09-29

main.cpp

/*
boot: Partition Table:e[0m
[Apr 13 23:04:26.809] e[0;32mI (65) boot: ## Label            Usage          Type ST Offset   Length   Flagse[0m
[Apr 13 23:04:26.809] e[0;32mI (73) boot:  0 nvs              WiFi data        01 02 00009000 00004000 00000000e[0m
[Apr 13 23:04:26.809] e[0;32mI (82) boot:  1 otadata          OTA data         01 00 0000d000 00002000 00000000e[0m
[Apr 13 23:04:26.820] e[0;32mI (90) boot:  2 app_0            OTA app          00 10 00010000 00180000 00000000e[0m
[Apr 13 23:04:26.825] e[0;32mI (98) boot:  3 fs_0             FS               01 82 00190000 00040000 00000000e[0m
[Apr 13 23:04:26.836] e[0;32mI (106) boot:  4 app_1            OTA app          00 11 001d0000 00180000 00000000e[0m
[Apr 13 23:04:26.842] e[0;32mI (115) boot:  5 fs_1             FS               01 82 00350000 00040000 00000000e[0m
[Apr 13 23:04:26.853] e[0;32mI (123) boot:  6 fs_ext           FS               01 82 00390000 00c00000 00000000e[0m
[Apr 13 23:04:26.859] e[0;32mI (131) boot: End of partition tablee[0m
*/

#include "mgos.h"
#include "mgos_system.h"

#include <stdio.h>
#include <string.h>
#include <sys/unistd.h>
#include <sys/stat.h>
#include "esp_err.h"
#include "esp_log.h"

static void timerHeapCb(void *args)
{
  LOG(LL_INFO, ("Heap Size: %d", mgos_get_heap_size()));
  LOG(LL_INFO, ("Free Heap Size: %d", mgos_get_free_heap_size()));
}

static void timerCb(void *args)
{
  static int counter = 0;
  LOG(LL_INFO, ("Timer called: %d", counter));

  FILE* f = fopen("/data/log.txt", "a");
  if (f == NULL)
  {
    LOG(LL_INFO, ("%s","Failed to open file for writing"));
    return;
  }
  fprintf(f, "Hello World - AAA! %d\n", counter++);
  fclose(f);
}

enum mgos_app_init_result mgos_app_init(void)
{
  LOG(LL_INFO, ("%s", "We are in the Entry point!!!!!"));
  mgos_set_timer(2500, MGOS_TIMER_REPEAT, timerCb, NULL);
  mgos_set_timer(300, MGOS_TIMER_REPEAT, timerHeapCb, NULL);
  return MGOS_APP_INIT_SUCCESS;
}

Back trace:

Jims-MacBook-Pro-486:objs jim$ /Users/jim/Library/Arduino15/packages/esp32/tools/xtensa-esp32-elf-gcc/1.22.0-80-g6c4433a-5.2.0/bin/xtensa-esp32-elf-addr2line -pfiaC -e File_System_Test_App.elf 0x4000c472 0x4015c027 0x40157ec6 0x4017aeda 0x4017a1a4 0x4017a2ae 0x4017d1be 0x40179cf6 0x40179d46 0x4016c129 0x4016d6d5 0x4016e87a 0x401704a0 0x401704cf 0x40181fdd 0x4016a2d9 0x40084002 0x400841c9

0x4000c472: ?? ??:0

0x4015c027: mbedtls_platform_zeroize at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/platform_util.c:78

0x40157ec6: mbedtls_mpi_zeroize at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/bignum.c:763

 (inlined by) mbedtls_mpi_free at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/bignum.c:109

0x4017aeda: ecdh_free_internal at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ecdh.c:284

 (inlined by) mbedtls_ecdh_free at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ecdh.c:321

0x4017a1a4: mbedtls_ssl_handshake_free at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_tls.c:7798

0x4017a2ae: ssl_handshake_wrapup_free_hs_transform at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_tls.c:7798

 (inlined by) mbedtls_ssl_handshake_wrapup at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_tls.c:6604

0x4017d1be: mbedtls_ssl_handshake_client_step at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_cli.c:3763

0x40179cf6: mbedtls_ssl_handshake_step at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_tls.c:7798

0x40179d46: mbedtls_ssl_handshake at /data/tmp/mos_prebuild/tmp/mos_libs/mbedtls/mbedtls/library/ssl_tls.c:7798

0x4016c129: mg_ssl_if_handshake at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

0x4016d6d5: mg_ssl_handshake at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

0x4016e87a: mg_recv_tcp at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

 (inlined by) mg_do_recv at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:582

0x401704a0: mg_if_can_recv_cb at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

 (inlined by) mg_ev_mgr_lwip_process_signals at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/common/platforms/lwip/mg_lwip_ev_mgr.c:60

0x401704cf: mg_lwip_if_poll at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

0x40181fdd: mg_mgr_poll at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/build/objs/moslib/mongoose/src/mg_net.c:1155

0x4016a2d9: mongoose_poll at /data/tmp/mos_prebuild/tmp/cesanta/mos-libs/mongoose/src/mgos_mongoose.c:239

0x40084002: mgos_mg_poll_cb at /data/fwbuild-volumes/latest/apps/File_System_Test_App/esp32/build_contexts/build_ctx_917480771/deps/freertos/src/mgos_freertos.c:257

0x400841c9: mgos_task at /data/fwbuild-volumes/latest/apps/File_System_Test_App/esp32/build_contexts/build_ctx_917480771/deps/freertos/src/mgos_freertos.c:257

Jims-MacBook-Pro-486:objs jim$

Another backtrace:

Jims-MacBook-Pro-486:objs jim$ /Users/jim/Library/Arduino15/packages/esp32/tools/xtensa-esp32-elf-gcc/1.22.0-80-g6c4433a-5.2.0/bin/xtensa-esp32-elf-addr2line -pfiaC -e File_System_Test_App.elf 0x4009234f 0x40081d31 0x40082215 0x4000bec7 0x4012f384 0x4012f40f 0x4012f463 0x40132ee7 0x40137f00 0x4013bcf6 0x4012f161

0x4009234f: multi_heap_free_impl at /opt/Espressif/esp-idf/components/heap/multi_heap.c:699

0x40081d31: heap_caps_free at /opt/Espressif/esp-idf/components/heap/heap_caps.c:365

0x40082215: _free_r at /opt/Espressif/esp-idf/components/newlib/syscalls.c:42

0x4000bec7: ?? ??:0

0x4012f384: mem_free at /opt/Espressif/esp-idf/components/lwip/lwip/src/core/mem.c:176

0x4012f40f: do_memp_free_pool at /opt/Espressif/esp-idf/components/lwip/lwip/src/core/memp.c:231

0x4012f463: memp_free at /opt/Espressif/esp-idf/components/lwip/lwip/src/core/memp.c:231

0x40132ee7: pbuf_free at /opt/Espressif/esp-idf/components/lwip/lwip/src/core/pbuf.c:1331

0x40137f00: ip4_input at /opt/Espressif/esp-idf/components/lwip/lwip/src/core/ipv4/ip4.c:454

0x4013bcf6: ethernet_input at /opt/Espressif/esp-idf/components/lwip/lwip/src/netif/ethernet.c:184

0x4012f161: tcpip_thread at /opt/Espressif/esp-idf/components/lwip/lwip/src/api/tcpip.c:483

Jims-MacBook-Pro-486:objs jim$
#2

@jim, to clarify, everything works OK without the extra partition - is that right?

#3

@cpq Not exactly.

If I eliminate the new partition and I stop writing a file anywhere, then I can use MDash with no problems, and I have a bunch of little programs that do that.

If I modify the logging timer callback to write to the default partition (code below) then I still have the core dump.

If I put the fs_ext partition back and I do not do any file writes, then I still get the core dump.

In all cases, it runs fine until I add the MDash token and, as far as I can tell, trigger MDash to call to the device by doing something like a ping or listing the FS.list.

Code that writes to the default partition (that runs fine until I add the MDash token):

static void timerCb(void *args)
{
  static int counter = 0;
  LOG(LL_INFO, ("Timer called: %d", counter));

//  FILE* f = fopen("/data/log.txt", "a");
  FILE* f = fopen("log.txt", "a");
  if (f == NULL)
  {
    LOG(LL_INFO, ("%s","Failed to open file for writing"));
    return;
  }
  fprintf(f, "Hello World - AAA! %d\n", counter++);
  fclose(f);
}
#4

According to my tests, this application core dumps only with mos latest (both cores enabled). Adding CONFIG_FREERTOS_UNICORE=y makes it run without problems.

#5

Great! That gets me moving forward again thank you. So it looks like a threadding bug?

By the way, if I do this:

build_vars:
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_FREERTOS_UNICORE=y}
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_4MB=}
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y CONFIG_ESPTOOLPY_FLASHSIZE="16MB"}

Then it still core dumps. To make it work I have to do it this way:

build_vars:
CONFIG_FREERTOS_UNICORE=y}
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_4MB=}
  ESP_IDF_SDKCONFIG_OPTS: ${build_vars.ESP_IDF_SDKCONFIG_OPTS} CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y CONFIG_ESPTOOLPY_FLASHSIZE="16MB" CONFIG_FREERTOS_UNICORE=y}

So is it true that the second line supersedes the prior line rather than appending?

Later today I’ll update the issue on Github. Thanks very much.

Dash.notify causes crash
#6

This is how it works for me:

build_vars:
  ESP_IDF_SDKCONFIG_OPTS: >
    ${build_vars.ESP_IDF_SDKCONFIG_OPTS} 
      CONFIG_ESPTOOLPY_FLASHSIZE_4MB=
      CONFIG_ESPTOOLPY_FLASHSIZE_16MB=y
      CONFIG_ESPTOOLPY_FLASHSIZE=16MB
      CONFIG_FREERTOS_UNICORE=y
#7

Okay that gives me a good idea how it works thank you.

I’ll update the issue on GitHub.

#8

I’m curious if this issue has been resolved? I can’t find the issue on GitHub. I’m doing some testing and it seems to be working, but if someone did something to fix this it would be good to know that for sure.

Thanks!