Sockets Error After Multiple HTTP Calls

[espruino-discuss3]

Posted at 2016-12-10 by .Neil

My code needs to load a web page multiple times. But after a few successful http calls it fails with "Uncaught Error: No free sockets".

I've removed my project-specific code to provide the simplest example of this error:

var tries=0;

function onInit() {
  digitalWrite(B9,1); // enable on Pico Shim V2
  Serial2.setup(115200, { rx: A3, tx : A2 });
  var wifi = require("ESP8266WiFi_0v25").connect(Serial2, function(err) {
    if (err) throw err;
    wifi.reset(function(err) {
      if (err) throw err;
      console.log("Connecting to WiFi");
      wifi.connect("SSID","password", function(err) {
        if (err) throw err;
        console.log("Connected");

        setInterval(function () {
          require("http").get("www.google.com", function(res) {
          });
          console.log("Attempt #" + ++tries);
        }, 250);


      });
    });
  });
  
}

onInit();

Google.com is simply an example; it fails with any website.

When running the code you'll see the number of attempts increment until it fails around #7 or #8. Apparently the require("http") call generates it. Oddly, changing the interval from 250 to something larger generates different errors but the end result is the same: the Espruino freezes.

I really need this to work as there is no workaround. Can anyone provide some guidance?

Thanks,

-Neil

[espruino-discuss3]

Posted at 2016-12-10 by @gfwilliams

You're calling it 4 times a second - realistically requests won't get handled that quickly and will pile up - the maximum number of open connections you can have is 5 on ESP8266.

So you really need to queue requests less than once a second. To be honest if it's more than one every 10 seconds you should probably be considering using WebSockets instead.

What's the other error you get with a bigger interval?

---

Posted at 2016-12-10 by .Neil

Hi Gordon, thanks for getting back to me so quickly.

I only reduced the interval to 250ms to quickly illustrate the problem BUT I think what I've done is created a new one (and obscured the still-present issue.)

Increase the interval to 15000 (15 seconds) and you'll see the real issue: the Espruino locks up after a few attempts and no longer makes the require("http") call.

My project only demands a one-hour interval but that's a long time to wait to see it lock up. The same lock-ups appear with a 15-second interval, occuring on two Espruino/ESP8266 boards I soldered up. (They still respond to pings for some reason...)

And different websites fail after a different number of attempts, but are consistent for each site (google.com always fails with 8 tries, espruino.com always with 4):
google.com: 8 attempts
espruino.com 4 attempts
travelocity.com 20 attempts
youtube.com 22 attempts
nasa.gov 23 attempts

I hope this helps.

Thanks,
-Neil

---

Posted at 2016-12-12 by @gfwilliams

Yes, I'd say there might be 2 issues then.

With the 15 sec interval, is the interpreter itself still responsive if you're connected to it via USB (were there any error messages beforehand?), and are you using up to date firmware?

Have you got a capacitor soldered across the ESP8266? Especially with the older rev 1.3 Pico boards, the diode supplying the power from USB really struggled to provide the peaks of power needed for the ESP8266, and a 10uF capacitor could really help.

---

Posted at 2016-12-12 by @gfwilliams

Also you might potentially be hitting a common Espruino pitfall.

If you're printing stuff to the console and then you power Espruino from your PC (without a terminal app running), Espruino will think there's a USB connection so will wait for the data it's sending to be received by the PC. Since nothing it reading, it'll stop executing when the buffer gets full - so after a few lines of text

---

Posted at 2016-12-14 by .Neil

Ok, ran some tests over the last few days:

1. I'm using firmware 1v89.
2. With the 15-second interval the interpreter is unresponsive when connected via USB and there are no error messages.
3. I retried with a one-hour interval and the results are the same.
4. Even the number of attempts are the same before it locks up: google.com still makes 8 attempts and locks up, espruino.com makes only 4. Same JS code as above, only changed the interval.
5. I added another interval to blink an LED every couple seconds to see if the results change when connecting to a simple power-only USB vs. a PC's USB: eventually the LED stops blinking, indicating the lock ups are still occurring.

I can certainly solder a cap between Vcc and GND, but I'm seeing a clear correspondence between the website and the number of require("http").get() calls before failure. This leads me to believe it's a problem in the software reading data rather than hardware. But what's different about the website data eludes me (nasa.gov's homepage has much more data than google.com but espruino makes more successful .get() calls before locking up...)

Does websockets use different underlying routines? I remember you saying to try websockets when I made 4 calls a second; can you tell me why?

Thanks,

Neil

---

Posted at 2016-12-15 by @gfwilliams

That's really strange - and it's with the code you posted above - nothing else? I know 1v89 has some issues with the newly added Arrow Functions - but you don't seem to be using them. I'll see if I can reproduce it here.

It'd be helpful if you could check process.memory().usage every so often while running the code though - it's possible there is a memory leak somewhere.

WebSockets use the same underlying code, but if you're making 4 requests a second it seems that really you'd be much better off keeping a single connection open, and just sending the data you want, when you want. By not having the overhead of opening/closing a connection you could send data much more often than 4 times a second if you wanted.

---

Posted at 2016-12-15 by @gfwilliams

Quick update: It looks like even process.memory() causes a lockup with 1v89 and that code.

My guess is it's some problem with the Garbage Collection - process.memory() forces it, and it's likely that after a few HTTP requests garbage collection would get run automatically and would hit this problem.

I've just re-flashed with latest firmware from here: http://www.espruino.com/binaries/git/commits/master/

(Do an 'Advanced Flash', copy the link to espruino_1v89.970_pico_1r3_wiznet.bin and paste it in)

And that seems to work reliably - however I would quite like to be able to find the commit that fixed it.

---

Posted at 2016-12-16 by CanyonCasa

This thread caught my eye as I'm experiencing a similar problem that does involve http. I've been working on a fairly simple Christmas light blink program that runs a while and just locks up kind of randomly. I haven't had time to post a simple test case. I was kind of guessing a memory leak but I didn't learn anything from process.memory(). Near as I can tell so far is that my setInterval timer just stops firing after a while. So it might be related to it. I tried 1v89, 1v89.7, and 1v87 on Espruino 1v4 board and it still fails.

---

Posted at 2016-12-16 by CanyonCasa

Should have said "doesn't involve http".

---

Posted at 2016-12-16 by @gfwilliams

Hopefully 1v90 should have fixed whatever was at fault. And generally memory leaks give you out of memory errors rather than lockups - having process.memory() lock up the device is a very specific error.

But worst case you could try E.enableWatchdog(1) - then if it locks up for more than 1 second it'll reboot.

It has been known for cheap USB power supplies to cause problems, and if you're using ESP8266 WiFi on an Original Espruino board you need a second voltage regulator

---

Posted at 2016-12-17 by .Neil

Thanks Gordon. Seeing a partial fix with 1v90; but now there's a clear memory leak.

I updated with 1v90.
I also soldered a 10uF ceramic capacitor between Vcc and GND on the ESP8266 Wifi Module.

Adding process.memory() to the code the leak is clearly visible. It makes about 15 require("http").get() calls before it's out of memory. I then see ERROR: Out of memory! followed by ERROR: Error processing Serial data handler - removing it.

Here's the code I used:

var tries=0;
function onInit() {
  digitalWrite(B9,1); // enable on Pico Shim V2
  Serial2.setup(115200, { rx: A3, tx : A2 });
  var wifi = require("ESP8266WiFi_0v25").connect(Serial2, function(err) {
    if (err) throw err;
    wifi.reset(function(err) {
      if (err) throw err;
      console.log("Connecting to WiFi");
      wifi.connect("SSID","password", function(err) {
        if (err) throw err;
        console.log("Connected");
        setInterval(function () {
          require("http").get("http://www.espruino.com", function(res) {
          });
          console.log("Attempt #" + ++tries);
          console.log(process.memory());
        }, 15000);
      });
    });
  });
  
}
onInit();

It's leaking 100-200 with each call. Oddly, it's not constant.

Any idea where the leak is?

---

Posted at 2016-12-17 by countxerox

Hi .Neil,

I have a pico connected to a ESP8266 development board and see the same memory leak problem you have found.

I added a couple of things and the leak seems to have disappeared completely (at least I think so - not really any clue of what a memory leak actually is!)

I have a 10uF electrolytic capacitor between Vcc and GND.

Also I removed the onInit() because I don't understand what that bit does?

var tries=0;

Serial2.setup(115200, { rx: A3, tx : A2 });
var wifi = require("ESP8266WiFi_0v25").connect(Serial2, function(err) {
  if (err) throw err;
  wifi.reset(function(err) {
    if (err) throw err;
    console.log("Connecting to WiFi");
    wifi.connect(WIFI_NAME, WIFI_PASS, function(err) {
      if (err) throw err;
      console.log("Connected");
      setInterval(function () {
        require("http").get("http://www.espruino.com", function(res) {
          console.log("Response: ",res);
          res.on('data', function(d) {
          });
        });
        console.log("Attempt #" + ++tries);
        console.log(process.memory());
      }, 15000);
    });
  });
});

It's been running a for a while now, here's the console log.

Attempt #121
{ "free": 4091, "usage": 1009, "total": 5100, "history": 583,
  "stackEndAddress": 536958448, "flash_start": 134217728, "flash_binary_end": 378024, "flash_code_start": 134234112, "flash_length": 393216 }
Response:  httpCRs {
  "headers": {
    "Date": "Sat, 17 Dec 2016 13:46:41 GMT",
    "Server": "Apache/2.4.18 (Ubuntu)",
    "Set-Cookie": "PHPSESSID=u97rcqv8b6e38cjertl64c6ti6; path=/",
    "Expires": "Thu, 19 Nov 1981 08:52:00 GMT",
    "Cache-Control": "no-store, no-cache, must-revalidate",
    "Pragma": "no-cache",
    "Vary": "Accept-Encoding",
    "Connection": "close",
    "Content-Type": "text/html; charset=UTF-8"
   },
  "httpVersion": "1.1",
  "statusCode": "200",
  "statusMessage": "OK"
 }

Does this maybe help to pin down the leak?

---

Posted at 2016-12-19 by @gfwilliams

It's possible that the problem is not having a data handler defined?

In pretty much all my tests (and most people's use-cases) the data from the HTTP request is used, and I wonder if not having the handler causes the socket data not to be freed.

It'd be worth a try - it's an easy thing to work around if so