Restarting on ESP8266 takes too long

General
1

AFAIK there was no such problem in 2.13.0 but after upgrading to 2.13.1 mgos_system_restart called from timer callback or mgos_system_restart_after takes almost half minute. For example see logs when I called mgos_system_restart_after(10):

[May  2 11:10:21.593] mgos_utils.c:38         Rebooting in 10 ms
[May  2 11:10:21.599] mgos_init.c:36          Init done, RAM: 52960 total, 46464 free, 45960 min free
[May  2 11:10:21.605] mgos_event.c:135        ev MOS0 triggered 0 handlers
[May  2 11:10:21.614] mg_net.c:85             0x3ffefb2c user ev=6 ev_data=0x3fffff00 flags=0x0 rmbl=0 smbl=0
[May  2 11:10:21.619] mgos_event.c:135        ev MOS2 triggered 0 handlers
[May  2 11:10:21.625] mgos_vfs.c:990          Unmounting filesystems
[May  2 11:10:21.628] mgos_vfs_dev.c:203      root refs 1
[May  2 11:10:21.634] mgos_vfs_dev.c:203      root refs 0
[May  2 11:10:21.637] mgos_vfs_dev.c:203      sfl0 refs 1
[May  2 11:10:21.639] mgos_vfs_dev.c:203      sfl0 refs 0
[May  2 11:10:21.643] bcn 0
[May  2 11:10:21.643] del if1
[May  2 11:10:21.643] usl
[May  2 11:10:21.643] mode : null
[May  2 11:10:21.645] mgos_system.c:42        Restarting
// (silence for ~ 27 seconds)
[May  2 11:10:48.457] 
[May  2 11:10:48.458]  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
[May  2 11:10:48.460] 
[May  2 11:10:48.460] load 0x40100000, len 1540, room 16

But if I call mgos_system_restart() directly from mgos_app_init then it takes ~ 3 seconds:

[May  2 11:11:55.069] mgos_system.c:42        Restarting
[May  2 11:11:58.231] 
[May  2 11:11:58.231]  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
[May  2 11:11:58.233] 
[May  2 11:11:58.233] load 0x40100000, len 1540, room 16

And same problem with { "id": 1, "jsonrpc": "2.0", "method": "Config.Save", "params": {"reboot": true} }:

[May  2 11:29:50.013] mgos_init.c:36          Init done, RAM: 52904 total, 45292 free, 44896 min free
{ "id": 1, "jsonrpc": "2.0", "method": "Config.Save", "params": {"reboot": true} }
[May  2 11:30:02.137] mg_rpc.c:293            Config.Save via UART UART0
[May  2 11:30:02.147] mgos_sys_config.c:231   Loading conf0.json
[May  2 11:30:02.268] mgos_sys_config.c:173   Saved to conf9.json
[May  2 11:30:02.276] 
[May  2 11:30:02.276] {"id":1,"src":"esp8266_E147EE","result":{"saved": true}}
[May  2 11:30:02.280] mgos_mongoose.c:66      New heap free LWM: 42720
[May  2 11:30:02.776] mgos_vfs.c:990          Unmounting filesystems
[May  2 11:30:02.781] bcn 0
[May  2 11:30:02.781] del if1
[May  2 11:30:02.781] usl
[May  2 11:30:02.783] mode : null
[May  2 11:30:02.783] mgos_system.c:42        Restarting
[May  2 11:30:29.620] 
[May  2 11:30:29.621]  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
[May  2 11:30:29.623] 
[May  2 11:30:29.623] load 0x40100000, len 1540, room 16

Minimal testcase

Application code:

#include "mongoose.h"
#include "mgos.h"
#include "mgos_app.h"

enum mgos_app_init_result mgos_app_init(void) {
  mgos_system_restart_after(10);
  return MGOS_APP_INIT_SUCCESS;
}

mos.yml:

name: test
version: 1.0

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

sources:
  - src

config_schema:
  - ["debug.level", 4]

libs:
  - origin: https://github.com/mongoose-os-libs/boards

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

This behavior is due to this commit

It has been fixed in latest

1 Like
3

I confused, your sistem reboots?
The log below is what appear when rebooted?

[May  2 11:10:48.457] 
[May  2 11:10:48.458]  ets Jan  8 2013,rst cause:2, boot mode:(3,6)
[May  2 11:10:48.460] 
[May  2 11:10:48.460] load 0x40100000, len 1540, room 16

I ask because I reboot my device but it only shows that.
In my code it should log more:

  const char *file_path = "/test.txt";
  FILE *fp;
  fp = fopen(file_path, "r");
  if (fp == NULL)
  {
    LOG(LL_INFO, ("File not exist, creating it"));
    fp = fopen(file_path, "w");
    if (fp == NULL)
      LOG(LL_INFO, ("Couldn't create it"));
    else
    {
      LOG(LL_INFO, ("File Created"));
      fprintf(fp, "This is testing for fprintf...\n");
      LOG(LL_INFO, ("Printed to file"));
      fputs("This is testing for fputs...\n", fp);
      LOG(LL_INFO, ("Printed to file 2"));
      fclose(fp);
      LOG(LL_INFO, ("File closed"));
    }
  }
  else
  {
    LOG(LL_INFO, ("File Opened"));
    fclose(fp);
    LOG(LL_INFO, ("File closed"));
  }

When I flash the code, its run ok and created the file.
Then I reboot by pressing a button on D0 for 2.5 seconds.

void check_reset_action(void *pArg)
{
  if (is_long_pressed())
  {
    mgos_system_restart_after(10);
  }
  (void)pArg;
}

But it doesn’t show the log for reading the file,
It only shows:

[Oct  7 12:08:30.639] mgos_utils.c:38         Rebooting in 10 ms
[Oct  7 12:08:30.639] mgos_vfs.c:990          Unmounting filesystems
[Oct  7 12:08:30.639] bcn 0
[Oct  7 12:08:30.639] del if1
[Oct  7 12:08:30.639] usl
[Oct  7 12:08:30.639] mode : null
[Oct  7 12:08:30.639] mgos_system.c:42        Restarting
[Oct  7 12:08:30.639] 
[Oct  7 12:08:30.639]  ets Jan  8 2013,rst cause:2, boot mode:(3,7)
[Oct  7 12:08:30.639] 
[Oct  7 12:08:30.639] ets_main.c 
[Oct  7 12:09:24.314]  ets Jan  8 2013,rst cause:4, boot mode:(3,7)
[Oct  7 12:09:24.314] 
[Oct  7 12:09:24.314] wdt reset
[Oct  7 12:09:24.314] ets_main.c