ESP32 memory leaks WIFI and MQTT

[espruino-discuss3]

Posted at 2019-10-09 by dwinfiel

I'm pretty new to Javascript so I'm hoping this is something that is easy to fix in my code. I've tried setting up my ESP32 to connect to WIFI and MQTT and no matter how I write it, I am getting memory leaks. Luckily, I do not need Bluetooth and I saw on here how to disable that (which practically doubled my available memory).

Below is my current version that will connect to my WIFI and publish MQTT. It will reconnect on a lost WIFI signal or lost MQTT connection. However, every 30 mins or so my free memory drops by 50 or so. I've tried writing this various different ways such as using setInterval vs setTimeout functions. I don't think I am mixing up the scope of any of my global variables. I even once tried putting everything all in one function and periodically resetting it to null which just seemed to make the problem worse. Is there a way to do this that will not run through all the memory?

//WIFI config
var wifi_options = 
   {
     ssid: 'xxxxxx',
     password: 'xxxxxx',
   };

//MQTT config
var mqtt_freq = 1000; //how often to send MQTT(ms)
var mqtt_options = 
  {
//    keep_alive: 0,
    server: "192.168.1.100",
    port: 1883,
  };

var led_speed = 500;
var wifi_stat;
var wifi_recon_count=0;
var wifi_pre_mem;
var wifi_post_mem;

var Wifi = require('Wifi');

//get wifi status every second
function iw1() {
  wifi_stat = Wifi.getDetails().status;
  //set led blink rate
  if(wifi_stat !== "connected") {led_speed = 100;}
  else {led_speed=500;}
  setTimeout(iw1,1000);
}
iw1();

//reconnect to WIFI (only try once every 30 seconds)  
function iw2(){
  if(wifi_stat !== "connected") {
    wifi_recon_count++;
    wifi_pre_mem = process.memory().free;
    print("WIFI disconnected: Reconecting...");
    Wifi.connect(wifi_options.ssid, {password: wifi_options.password});
    wifi_post_mem = process.memory().free;
  }
  setTimeout(iw2,1000*30);
}
iw2();


//BLINK LED
var  D2_setting = false;
function iLED () {
  D2_setting = !D2_setting;
  digitalWrite(D2, D2_setting);
  
  setTimeout(iLED, led_speed);
}
iLED();



//mqtt globals
var mqtt_r=require("MQTT");
mqtt = mqtt_r.create(mqtt_options.server, {
  port: mqtt_options.port,//8883
  });
var mqtt_conn_count = 0;
var mqtt_stat = false; 

function mqt0(){
  function mqt1 () {
    mqtt_stat = mqtt.connected;
  }
  var imq1 = setInterval(mqt1,1000);
  
  //Reconnect MQTT if disconnected:
  function mqt2() {
    if (mqtt_stat === false){
      mqtt_conn_count++;
      print("MQTT disconnected, reconnecting...");
      mqtt.connect();
    }
  }
  var imq2 = setInterval(mqt2,30*1000); //only try to reconnect every xx seconds
  
  //publish free memory every minute
  function mqt3(){
    if (mqtt_stat === true){
      free_mem = process.memory().free; 
      print("memory publishing: " + free_mem);
      mqtt.publish("process.memory()",free_mem);}
  }  
   var imq3 = setInterval(mqt3,1000*60);

  //loop back to mqt0 and clear intervals
  setTimeout(function(){
    clearInterval(imq1);
    clearInterval(imq2);
    clearInterval(imq3);
    imq1 = null;
    imq2 = null;
    imq3 = null;
    mqt0();
  },60*1000*15); //setloop time to 15 mins
}
mqt0();

[espruino-discuss3]

Posted at 2019-10-10 by Robin

Wed 2019.10.09

Hello @dwinfiel

Would you mind posting the results of process.env and separatelyprocess.memory() before uploading, then again after the memory leak is observed, so that we may get a better understanding of the scope of this issue. Thanks

---

Posted at 2019-10-10 by AkosLukacs

Hi!

Just connecting to the AP, and then saving Wifi credentials with Wifi.save() was the best for me.
Wifi tries to reconnect if disconnected from the AP without any explicit code. Connect and reconnect sometimes completes quickly, sometimes it takes longer. And this can mess if you have timed reconnects.

Also, in the function

function iw2(){
  if(wifi_stat !== "connected") {
    wifi_recon_count++;
    wifi_pre_mem = process.memory().free;
    print("WIFI disconnected: Reconecting...");
    Wifi.connect(wifi_options.ssid, {password: wifi_options.password});
    wifi_post_mem = process.memory().free;
  }
  setTimeout(iw2,1000*30);
}

The status can be for example connecting, if the function runs just after a random disconnect, while the ESP is still trying to connect. Calling Wifi.connect() while connecting caused all kinds of strange behaviour for me.

---

Posted at 2019-10-11 by maze1980

I guess there is a better way: Do not create new timer every 1000ms, but only once. Just to quote one function:

//get wifi status every second
function iw1() {
  wifi_stat = Wifi.getDetails().status;
  //set led blink rate
  if(wifi_stat !== "connected") {led_speed = 100;}
  else {led_speed=500;}
  setTimeout(iw1,1000);
}
iw1();

And how to do it better:

//get wifi status every second
function iw1() {
  wifi_stat = Wifi.getDetails().status;
  //set led blink rate
  if(wifi_stat !== "connected") {led_speed = 100;}
  else {led_speed=500;}
}
iw1();
setInterval(iw1,1000);

While there is a garbage collection, it might be called too late, or not working properly - I didn't look into it. But if you call setTimeout every 1000ms instead of setInterval once there's a really high chance it'll allocate a new block of memory for a new timer every 1000ms.
The other functions shall be modified accordingly.

---

Posted at 2019-10-14 by dwinfiel

Thank everyone for their suggestions. I have just gotten back to trying this again (had some OT at work and other things going on).

I am starting with a fresh install of everything (even my OS because when I tried to update Debian from stretch to buster, I broke it).

The ESP32 board that I'm using are MELIFE 2 ESP-32S (ESP-WROOM-32 module with 4MB flash, no pSRAM).

I've done a fresh flash of the firmware and I get the following right after flashing:

>ESP32.getState();
={
  sdkVersion: "v3.1.3-dirty",
  freeHeap: 35712, BLE: true, Wifi: true, minHeap: 33112 }

>process.memory();
={ free: 2264, usage: 36, total: 2300, history: 13,
  gc: 0, gctime: 1.876 }

>process.env
={
  VERSION: "2v04",
  GIT_COMMIT: "3956264e",
  BOARD: "ESP32",
  FLASH: 0, RAM: 524288,
  SERIAL: "3c71bff1-179c",
  CONSOLE: "Serial1",
  MODULES: "Flash,Storage,hea" ... "r,crypto,neopixel",
  EXPTR: 1073484860 }

I then disabled bluetooth and get much more memory:

>ESP32.enableBLE(false); 
>process.memory();
={ free: 4071, usage: 29, total: 4100, history: 0,
  gc: 0, gctime: 3.209 }

Then I turned on WIFI using

var ssid = 'YOUR_SSID';
var password = 'YOUR_SSID_PASSWORD';

var wifi = require('Wifi');
wifi.connect(ssid, {password: password}, function() {
    console.log('Connected to Wifi.  IP address is:', wifi.getIP().ip);
    wifi.save(); // Next reboot will auto-connect
});

My WIFI does not re-connect on it's own (if I say reboot my WIFI router). However, it does connect when I reboot the ESP32.

I'll try some of the other suggestions and see what I get.

---

Posted at 2019-10-15 by dwinfiel

I've modified the code to not try to connect if wifi status is "connecting". I've also modified it so that it won't try to reconnect MQTT if WIFI is disconnected. While connected with USB, I've tried starting and stopping my WIFI and/or my MQTT server so that I can see the printout from the ESP32. I'm noticing a few errors I'm hoping someone can clarify what the following errors are:

E (265203) event: post event to user fail!
E (268048) event: post event to user fail!
E (270893) event: post event to user fail!
E (455363) event: post event to user fail!

I get the following after reseting:

WARNING: gap set scan error code = 103
WARNING: set rssi scan not implemeted yet

Also, I've noticed the device go into a state where the Wifi status is "NO_AP_FOUND" and it wouldn't reconnect. Once I disconnected power and re-connected then the WIFI was able to reconnect.

---

Posted at 2019-10-15 by Robin

Mon 2019.10.14

Thank you for the above postings @dwinfiel

Are we still dealing with a memory leak? If so,

would you please load your code and re-run process.memory(); posting the results of each interval after several iterations. We would be seeking the value of ':free' to observe how much space is available for Espruino to do it's thing while running, and also if there is in fact a perceived leak after several events have been confirmed.    or, . . . maybe run the above snippet inside a setInterval() and using console.log() to directly output to the Left-Hand console side of the WebIDE.

Errors indicated above #6 are unknown to me.
> 'does not re-connect on it's own (if I say reboot my WIFI router)'

What logic is being used to reboot or dis-connect/re-connect when just the router is rebooted? Has a sufficient time interval been used to allow internal WiFI workings to settle?

---

Posted at 2019-10-16 by dwinfiel

@robin,

After flashing new firmware to the ESP32, disabling Bluetooth, saving my wifi settings using the following:

var ssid = 'xxxx'; 
var pswd = 'xxxx'; 
var wifi = require('Wifi');
wifi.stopAP();

wifi.connect(ssid, {password: pswd},function(){
//    console.log('Connected to Wifi.  IP address is:', wifi.getIP().ip);
    wifi.save(); // Next reboot will auto-connect
});

I get the following memory (after sending a ESP32.reboot):

>process.memory();
={ free: 4021, usage: 79, total: 4100, history: 0,
  gc: 0, gctime: 3.2 }

I found that my board does run the event wifi.on('disconnected',function()), at least sometimes. So I am trying the following code:

var wifi = require('Wifi');
var iwico = setInterval(wico,999999999);
wifi.stopAP();

wifi.on('disconnected',function(){
  //print("wifi disconnected");
  console.log('Wifi disconnected');
  clearInterval(iwico);
  iwico = setInterval(wico,1000*30);
  
});

wifi.on('connected',function(){
  //print("wifi connected");
  console.log('Connected to Wifi.  IP address is:', wifi.getIP().ip);
  clearInterval(iwico);
});


function wico() {
  console.log('trying to reconnect');
  wifi.restore();
}

function fmem() {
  free_mem = process.memory().free;
  print('free mem: ' + free_mem);
  setTimeout(fmem,1000);
}
fmem();

After performing a ESP32.reboot, I get the following:

>process.memory();
={ free: 3985, usage: 115, total: 4100, history: 0,
  gc: 0, gctime: 3.382 }
free mem: 3981

And as long as my Wifi doesn't disconnect it seems to stay steady at 3981. Shortly after I shut off my WIFI, I get a few error messages and then my memory drops to 3963. It continues to drop each time it tries to reconnect. After a couple of minutes, I turned my WIFI back on. Just before I turned it on the free memory was down to 3895. After it finished reconnecting it dropped more, down to:
3859.

Then it stays steady ad 3859. If I wait a few more minutes and turn off my WIFI again it doesn't seem to catch the change in WIFI status. If I manually type in wifi.getStatus(), I get the following

={
  station: "connected",
  ssid: "",
  bssid: "00:00:00:00:00:00",
  channel: 0, rssi: 0,
  htMode: "HT20",
  authMode: "wpa2",
  mode: "STA",
  powersave: "modem"
 }

For some reason my ssid is now deleted. Any idea why it does that? Maybe I'm shutting my WIFI off too quickly. If I turn my WIFI back on, it doesn't re-connect a second time. I'll set it to run overnight and see how much, if any memory loss I get if I don't manually shut off the WIFI.

---

Posted at 2019-10-17 by dwinfiel

I tried resetting my router and then waiting about an hour before resetting a 2nd time and the ESP32 successfully reconnected, but memory dropped to 3799 after reconnecting. I just restarted my router a 3rd time and the ESP32 memory dropped to 3781 and then 3746 and then 3711 all while disconnected. After reconnecting it is down to 3709.

---

Posted at 2019-10-17 by Robin

'After flashing new firmware to the ESP32'

Are we still at ver 2.04 ?

On a S.W.AG. hunch, try console.log() the value of 'iwico' to see if the handle is changing. Wondering if the call to setInterval() is gobbling up those bytes?

---

Posted at 2019-10-17 by dwinfiel

Yes my version is 2.04. Would trying an older vesion help? Not sure what you want me to console.log(), if I just put that I get "=undefined". When I do >E.getSizeOf(global, 2), I get the following:

>E.getSizeOf(global, 2)
=[
  {
    name: "\xFF",
    size: 63,
    more: [
      {
        name: "timers",
        size: 12 },
      {
        name: "watches",
        size: 3 },
      {
        name: "net",
        size: 3 },
      {
        name: "modules",
        size: 15 },
      {
        name: "BLE_DEV_N",
        size: 4 },
      {
        name: "history",
        size: 24 }
     ]
   },
  {
    name: "wico",
    size: 4,
    more: [
      {
        name: "\xFFcod",
        size: 2 }
     ]
   },
  {
    name: "fmem",
    size: 4,
    more: [
      {
        name: "\xFFcod",
        size: 2 }
     ]
   },
  {
    name: "ssid",
    size: 2 },
  {
    name: "pswd",
    size: 3 },
  {
    name: "wifi",
    size: 12,
    more: [
      {
        name: "#ondisconnected",
        size: 5 },
      {
        name: "#onconnected",
        size: 5 }
     ]
   },
  {
    name: "iwico",
    size: 2 },
  {
    name: "process",
    size: 3,
    more: [  ]
   },
  {
    name: "free_mem",
    size: 2 },
  {
    name: "console",
    size: 3,
    more: [  ]
   },
  {
    name: "ReferenceError",
    size: 8,
    more: [
      {
        name: "prototype",
        size: 6 }
     ]
   },
  {
    name: "E",
    size: 2,
    more: [  ]
   }
 ]

There were not any memory loss during the night (WIFI probably didn't loose connection). Resetting it this morning dropped it from 3696 (what it dropped to after running a few commands such as the E.getSizeOf(global, 2)) to 3605 by the time it reconnected.

---

Posted at 2019-10-18 by Robin

Thr 2019.10.17

'Not sure what you want me to console.log()'

Examples at:

https://www.w3schools.com/js/js_output.asp
http://www.espruino.com/Reference#l_console_log

from #10 'On a S.W.AG. hunch, try console.log() the value of 'iwico''

console.log( iwico );

Thank you @dwinfiel for the postings. This will assist others should we not locate the offending binary culprit. While I'm primarily a supporter of official supported boards, I don't have access to an ESP32 to test your code. However, we still have a bit more to do to gather sufficient information to both rule out what isn't the cause and hopefully locate what is going on.

Based on your postings, my first impression is that although you have diagnosed down to the connect/disconnect event and have observed memory decrease, I don't believe this is a result of the internal workings of Espruino.

Possibility 1 > ref L8 in listing 3 of post #8

It might be that clearInterval(iwico); is being passed a bad handle, an error is being thrown and not detected. (by we humans) One way to test this would be to place that line within a try/catch block and also monitor L9 in post #11 . L9 seems to indicate unused timers lying around, maybe not getting cleared correctly, or getting stepped on and a new one created, bumping up the handle count. If that value grows, would be a good indicator we are on the right track.

It is indicated in post #1 that Javascript is new to you, so forgive me if this is too basic;

https://www.w3schools.com/js/js_errors.asp

replace line 8 with the following:

try {
  console.log( "calling clear interval + [" + iwico + "]" );
  clearInterval(iwico);
} catch( e ) {
  console.log( "Err at line xx " + e.message );
  console.log( process.memory().free );
}

Possibility 2

L28 is getting called, while a timeout is still being processed, also not freeing up memory.

https://www.w3schools.com/js/js_timing.asp

Use the same technique above to monitor the handle returned from that function. Also note that to clear a running one needs clearTimeout() which is subtly different from clearInterval(). The w3schools website has "TryIt" pages to speed understanding.

Possibility 3

Lines like #7 console.log('Wifi disconnected'); within the WiFi core functions are causing unique new strings on each invocation. This would gobble up memory. As a test, comment out those lines, one at a time-and-test, then the next one, and so on, then also monitor :free

One way around that would be to define the string once outside the function, then pass the variable name to the console.log() function, rather than a new string each invocation.

Possibility 4 > 'Would trying an older version help?'

It would be a good comparison test, but we are not there yet. Too time consuming to flash, with most likely no additional troubleshooting detail.

The above should provide sufficient detail to narrow this down.