Need network troubleshooting help

[espruino-discuss]

Posted at 2015-12-16 by tve

I'm having a problem with http / sockets on the esp8266 that falls into the "how can this possibly be?" category at the moment. I have a little test program that issues a POST request every 200ms and after a few hundred requests the object returned by http.request ends up not having an end() function! The end function is part of the prototype, if I understand correctly, so that must get messed-up somehow? I'm looking for some guidance about what to try, where to insert checks, etc.
The same test program runs fine on linux, so either there is timing involved or something somewhere else in the esp8266 implementation that is messing JSvars up, at this point I don't understand what kind of messing up I should even be looking for...

The test program is:

var postUrl = "http://h.voneicken.com:4567/temp";

var http = require("http");

var int1, int2;

var errCnt = 0;
var okCnt  = 0;

function sendTemp(temp) {
  var q = url.parse(postUrl + "?temp=" + temp);
  q.method = "POST";
  q.headers = {'Content-Length': 0};
  //console.log("REQ:", q);
  var req = http.request(q, function(resp) {
    resp.on('data', function(d) { if (d !== 'OK') console.log("Got unexpected response:", d); });
    resp.on('close', function(gotErr) {
      if (!gotErr && resp.statusCode !== "200") console.log("Got HTTP code", resp.statusCode);
      if (gotErr || resp.statusCode !== "200") errCnt++; else okCnt++;
    });
    resp.on('error', function(err) { console.log("HTTP response error: ", err.message); });
  });
  req.on('error', function(err) { console.log("HTTP request error: ", err.message); errCnt++; });
  req.on('close', function(gotErr) { console.log("HTTP done"); });
  if (typeof req.end === 'function') {
    req.end();
  } else {
    console.log("OOPS, no end function:", req);
    trace(req);
    clearInterval(int1);
    clearInterval(int2);
  }
}

var t = 10.0;
int1 = setInterval(function(){sendTemp(t); t+=0.01;}, 200);
int2 = setInterval(function(){console.log("*** OK:"+okCnt, "ERR:"+errCnt, process.memory());}, 10000);

The output is:

*** OK:49 ERR:0 { "free": 722, "usage": 301, "total": 1023, "history": 129 }
*** OK:99 ERR:0 { "free": 722, "usage": 301, "total": 1023, "history": 129 }
*** OK:149 ERR:0 { "free": 722, "usage": 301, "total": 1023, "history": 129 }
*** OK:199 ERR:0 { "free": 722, "usage": 301, "total": 1023, "history": 129 }
*** OK:249 ERR:0 { "free": 722, "usage": 301, "total": 1023, "history": 129 }
OOPS, no end function: { "type": 1,
  "#onconnect": function (resp) {resp.on("data",function(d){if(d!=="OK")console.log("Got unexpected response:",d)});resp.on("close",function(gotErr){if(!gotErr&&resp.statusCode!=="200")console.log("Got HTTP code",resp.statusCode);if(gotErr||resp.statusCode!=="200")errCnt++;else okCnt++});resp.on("error",function(err){console.log("HTTP response error: ",err.message)})},
  "res": {  },
  "opt": {
    "protocol": "http:",
    "method": "POST",
    "host": "h.voneicken.com",
    "path": "/temp?temp=12.54",
    "pathname": "/temp",
    "search": "?temp=12.54",
    "port": 4567,
    "query": "temp=12.54",
    "headers": { "Content-Length": 0 }
   },
  "#onerror": function (err) {console.log("HTTP request error: ",err.message);errCnt++},
  "#onclose": function (gotErr) {console.log("HTTP done")}
 }

[espruino-discuss]

Posted at 2015-12-16 by tve

Couldn't get it into one post: the output of the trace(req) call is:

#354[r2,l1] Object {
  #355[r1,l2] Name String [2 blocks] "__proto__"    #368[r1,l1] ...
 
  #369[r1,l2] Name String [1 blocks] "type"= int 1
  #368[r1,l2] Name String [2 blocks] "#onconnect"    #482[r1,l1] Function {
      #481[r1,l2] Name Param "resp"         undefined
      #129[r1,l2] Name String [1 blocks] "ÿcod"        #274[r1,l1] FlatString [29 blocks] "resp.on(\"data\",function(d){if(d!==\"OK\")console.log(\"Got unexpected response:\",d)});resp.on(\"close\",function(gotErr){if(!gotErr&&resp.statusCode!==\"200\")console.log(\"Got HTTP code\",resp.statusCode);if(gotErr||resp.statusCode!==\"200\")errCnt++;else okCnt++});resp.on(\"error\",function(err){console.log(\"HTTP response error: \",err.message)})"
      #131[r1,l2] Name String [1 blocks] "ÿsco"        #526[r3,l3] Function {
          #525[r1,l2] Name Param "temp"             #374[r2,l1] Double 12.54
          #524[r1,l3] Name String [2 blocks] "return"            undefined
          #522[r1,l2] Name String [1 blocks] "q"            #517[r2,l1] ...
 
          #511[r1,l2] Name String [1 blocks] "req"            #354[r2,l2] ...
 
        }
    }
  #303[r1,l2] Name String [1 blocks] "res"    #135[r1,l1] Object {
      #138[r1,l2] Name String [2 blocks] "__proto__"        #354[r2,l2] ...
 
    }
  #304[r1,l2] Name String [1 blocks] "opt"    #517[r2,l1] Object {
      #514[r1,l2] Name String [2 blocks] "protocol"        #513[r1,l1] String [1 blocks] "http:"
      #507[r1,l2] Name String [2 blocks] "method"        #521[r1,l1] String [1 blocks] "POST"
      #503[r1,l2] Name String [1 blocks] "host"        #505[r1,l1] String [2 blocks] "h.voneicken.com"
      #500[r1,l2] Name String [1 blocks] "path"        #502[r1,l1] String [2 blocks] "/temp?temp=12.54"
      #498[r1,l2] Name String [2 blocks] "pathname"        #499[r1,l1] String [1 blocks] "/temp"
      #493[r1,l2] Name String [2 blocks] "search"        #495[r1,l1] String [2 blocks] "?temp=12.54"
      #490[r1,l2] Name String [1 blocks] "port"        #491[r1,l1] Integer 4567
      #487[r1,l2] Name String [2 blocks] "query"        #489[r1,l1] String [2 blocks] "temp=12.54"
      #518[r1,l2] Name String [2 blocks] "headers"        #519[r1,l1] Object {
          #512[r1,l2] Name String [3 blocks] "Content-Length"= int 0
        }
    }
  #315[r1,l2] Name String [2 blocks] "#onerror"    #305[r1,l1] Function {
      #306[r1,l2] Name Param "err"         undefined
      #313[r1,l2] Name String [1 blocks] "ÿcod"        #307[r1,l1] FlatString [6 blocks] "console.log(\"HTTP request error: \",err.message);errCnt++"
      #314[r1,l2] Name String [1 blocks] "ÿsco"        #526[r3,l3] Function {
          #525[r1,l2] Name Param "temp"             #374[r2,l1] Double 12.54
          #524[r1,l3] Name String [2 blocks] "return"            undefined
          #522[r1,l2] Name String [1 blocks] "q"            #517[r2,l1] ...
 
          #511[r1,l2] Name String [1 blocks] "req"            #354[r2,l2] ...
 
        }
    }
  #326[r1,l2] Name String [2 blocks] "#onclose"    #318[r1,l1] Function {
      #319[r1,l2] Name Param "gotErr"         undefined
      #324[r1,l2] Name String [1 blocks] "ÿcod"        #321[r1,l1] FlatString [3 blocks] "console.log(\"HTTP done\")"
      #325[r1,l2] Name String [1 blocks] "ÿsco"        #526[r3,l3] Function {
          #525[r1,l2] Name Param "temp"             #374[r2,l1] Double 12.54
          #524[r1,l3] Name String [2 blocks] "return"            undefined
          #522[r1,l2] Name String [1 blocks] "q"            #517[r2,l1] ...
 
          #511[r1,l2] Name String [1 blocks] "req"            #354[r2,l2] ...
 
        }
    }
}

What looks a little suspicious to me is the #355[r1,l2] Name String [2 blocks] "__proto__" #368[r1,l1] ... part. On a req object that works it's:

>trace(req)
#97[r2,l1] Object {
  #98[r1,l2] Name String [2 blocks] "__proto__"    #93[r2,l1] Object {
      #94[r1,l2] Name String [2 blocks] "constructor"        #89[r2,l1] NativeFunction 0x40221210 (1) {
          #90[r1,l2] Name String [2 blocks] "prototype"            #93[r2,l2] ...
 
        }
    }
  #102[r1,l2] Name String [1 blocks] "type"= int 1
...

---

Posted at 2015-12-16 by tve

Mhh, I'm now seeing that #355[r1,l2] Name String [2 blocks] "__proto__" #368[r1,l1] ... refers to #368, which is #368[r1,l2] Name String [2 blocks] "#onconnect" #482[r1,l1] Function {..., right?

---

Posted at 2015-12-16 by tve

Running this some more, I hit:

ASSERT((!jsvGetNextSibling(var) && !jsvGetPrevSibling(var)) || jsvIsRefUsedForData(var) || (jsvIsName(var) && (jsvGetNextSibling(var)==jsvGetPrevSibling(var)))) FAILED AT src/jsvar.c:402
  #1[r3,l2] Object {
    #2[r1,l2] ASSERT((!jsvGetNextSibling(var) && !jsvGetPrevSibling(var)) || jsvIsRefUsedForData(var) || (jsvIsName(var) && (jsvGetNextSibling(var)==jsvGetPrevSibling(var)))) FAILED AT src/jsvar.c:402

It does smell like some JSvars corruption... If you have any hints on what to look for, that might help me a lot tracking it down!

Mhh, I have the sneaky feeling that the answer is going to be "you must be unlocking something that is still used afterwards"... If that's the case, how to best troubleshoot it?

---

Posted at 2015-12-16 by @gfwilliams

Mhh, I'm now seeing that ... refers to #368

Yes, when dumping, so as not to get in infinite loops, it only prints things once - so if it printed it above it'd add ...

Sounds like an unlock as you say - IIRC the builtins are checked for by looking at __proto__.constructor to see if it's a native function with a certain address, but the way __proto__ links to #onconnect instead looks broken.

The fact it's actually all vaguely intact (vars pointing to other vars) looks like it's not actual corruption. It is probably just accidentally freeing something.

One thing that might help is to run trace at several points during execution, and to diff it. It might show something?

Do you have any kind of debugger? Sometimes when this kind of thing happens (if it's repeatable) I figure out what the variable number was, and then add a conditional breakpoint on jsvFreePtr. If you can find where the assert is happening it might actually be right at the point where the variable that has the problem is being unlocked.

The other option is @Kolban had spent some time making a windows-based test harness for the ESP8266 code. I'm not sure if it's working, but it is in the repo. If you can run that locally you might be able to reproduce the issue on a PC, and then you can debug it better?

Also, you can try editing build_platform_config.py and replacing RESIZABLE_JSVARS with a fixed size of 1000. That'll force the Linux build to use 12 byte JsVars like the ESP8266, which might make it more likely that problems will occur?

---

Posted at 2015-12-17 by tve

Gordon, could you tell me where 'key' gets locked in https://github.com/espruino/Espruino/blob/master/libs/network/jswrap_net.c#L169-L172

          key = jsvAsArrayIndexAndUnLock(key); // make sure "0" gets made into 0
          jsvMakeIntoVariableName(key, val);
          jsvAddName(query, key);
          jsvUnLock2(key, val);

---

Posted at 2015-12-17 by tve

I added some printf for each Alloc and each Free. Starting from the beginning, this is the original JS code:

function sendTemp(temp) {
  var q = url.parse(postUrl + "?temp=" + temp);
  q.method = "POST";
  q.headers = {'Content-Length': 0};
  //console.log("REQ:", q);
  var req = http.request(q, function(resp) {
    resp.on('data', function(d) { if (d !== 'OK') console.log("Got unexpected response:", d); });
    resp.on('close', function(gotErr) {
      if (!gotErr && resp.statusCode !== "200") console.log("Got HTTP code", resp.statusCode);
      if (gotErr || resp.statusCode !== "200") errCnt++; else okCnt++;
    });
    resp.on('error', function(err) { console.log("HTTP response error: ", err.message); });
  });
  req.on('error', function(err) { console.log("HTTP request error: ", err.message); errCnt++; });
  req.on('close', function(gotErr) { console.log("HTTP done"); });
  if (typeof req.end === 'function') {
    req.end();
  } else {
    console.log("OOPS, no end function @"+(okCnt+errCnt));
    //console.log("OOPS, no end function:", req);
    trace(req);
    clearInterval(int1);
    clearInterval(int2);
  }
}

Here is what happens when it crashes (always on the 255th http request!):

OOPS, no end function @254
#359[r2,l1] Object {
  #360[r1,l2] Name String [2 blocks] "__proto__"    #373[r1,l1] ...
 
  #374[r1,l2] Name String [1 blocks] "type"= int 1
  #373[r1,l2] Name String [2 blocks] "#onconnect"    #484[r1,l1] Function {
      #483[r1,l2] Name Param "resp"         undefined
...

Notice how the proto links to #373 and that's occupied by on_connect.

---

Posted at 2015-12-17 by tve

Here's the debug output:

>jswrap_net_connect
clientRequestNew
1
Alloc 71
Alloc 141
Alloc 151
Alloc 153
Free 359
Free 360
2
Alloc 359
Alloc 360
Alloc 362
Alloc 273
Free 373    <=============
Free 374
3
Alloc 373
Alloc 374
Free 373
4
Alloc 373
Alloc 376
Alloc 274
5
Alloc 275
Alloc 276
6
Alloc 308
x clientRequestNew

So #373 gets freed in clientRequestNew and the "1", "2", ... markers are from printf's that divide up the function:

JsVar *clientRequestNew(SocketType socketType, JsVar *options, JsVar *callback) {
  printf("clientRequestNew\n");
  JsVar *arr = socketGetArray(HTTP_ARRAY_HTTP_CLIENT_CONNECTIONS,true);
  if (!arr) return 0;
  JsVar *req, *res = 0;
  printf("1\n");
  if ((socketType&ST_TYPE_MASK)==ST_HTTP) {
    res = jspNewObject(0, "httpCRs");
  printf("2\n");
    if (!res) { jsvUnLock(arr); return 0; } // out of memory?
    req = jspNewObject(0, "httpCRq");
  } else {
    req = jspNewObject(0, "Socket");
  }
  printf("3\n");
  if (req) { // out of memory?
   socketSetType(req, socketType);
  printf("4\n");
   if (callback != NULL)
     jsvUnLock(jsvAddNamedChild(req, callback, HTTP_NAME_ON_CONNECT));

  printf("5\n");
   jsvArrayPush(arr, req);
   if (res)
     jsvObjectSetChild(req, HTTP_NAME_RESPONSE_VAR, res);
  printf("6\n");
   jsvObjectSetChild(req, HTTP_NAME_OPTIONS_VAR, options);
  }
  jsvUnLock2(res, arr);
  printf("x clientRequestNew\n");
  return req;
}

So the proto somehow gets freed in jspNewObject(0, "httpCRq"); on the 255-th request... Mhhh, is the reference or lock count perhaps a byte and only allows 255 references/locks? Does this mean the problem is that the httpCRq object that gets created for each request doesn't get freed or unlocked somewhere?

---

Posted at 2015-12-17 by tve

Mhh, to me it looks like connection objects just don't get freed. After running one HTTP request I see the following if I do a trace():

 1[r2,l1] Object {
  #2[r1,l2] Name String [1 blocks] "ÿ"    #3[r1,l2] Object {
      #6[r1,l2] Name String [2 blocks] "timers"        #8[r2,l1] Array(0) [ ]
      #9[r1,l2] Name String [2 blocks] "watches"        #11[r2,l1] Array(0) [ ]
      #14[r1,l2] Name String [1 blocks] "net"        #12[r1,l2] String [2 blocks] "\x04\x00\x00\x00\x00ÿÿÿ"
      #15[r1,l2] Name String [2 blocks] "history"        #19[r1,l1] Array(2) [
          #20[r1,l2] Name Integer 0            #16[r1,l1] String [2 blocks] "echo(0);"
          #56[r1,l2] Name Integer 1            #36[r1,l1] String [16 blocks] "setTime(1.450337081404E9);var postUrl=\"http://h.voneicken.com:4567/temp\";var http=require(\"http\");var int1,int2;var errCnt=0;var okCnt=0;"
        ]
      #26[r1,l2] Name String [2 blocks] "modules"        #24[r1,l1] Object {
          #27[r1,l2] Name String [1 blocks] "http"            #23[r2,l1] ...
 
        }
      #297[r1,l2] Name String [2 blocks] "HttpCC"        #299[r1,l1] Array(1) [
          #332[r1,l2] Name Integer 0            #324[r2,l1] Object {
              #325[r1,l2] Name String [2 blocks] "__proto__"                #320[r2,l1] ...
 
              #329[r1,l2] Name String [1 blocks] "type"= int 1
              #328[r1,l2] Name String [2 blocks] "#onconnect"                #264[r1,l1] Function {
                  #265[r1,l2] Name Param "resp"                     undefined
                  #295[r1,l2] Name String [1 blocks] "ÿcod"                    #266[r1,l1] FlatString [29 blocks] "resp.on(\"data\",function(d){if(d!==\"OK\")console.log(\"Got unexpected response:\",d)});resp.on(\"close\",function(gotErr){if(!gotErr&&resp.statusCode!==\"200\")console.log(\"Got HTTP code\",resp.statusCode);if(gotErr||resp.statusCode!==\"200\")errCnt++;else okCnt++});resp.on(\"error\",function(err){console.log(\"HTTP response error: \",err.message)})"

I thought the connection gets removed from the HttpCC array here: https://github.com/espruino/Espruino/blob/master/libs/network/socketserver.c#L548 and I verified with a printf that this indeed gets executed. I must not be understanding something correctly...

---

Posted at 2015-12-17 by @gfwilliams

could you tell me where 'key' gets locked in github.com/espruino/Espruino/blo­b/master/libs/network/jswrap_net.c#L169-­L172

It's here? https://github.com/espruino/Espruino/blob/master/libs/network/jswrap_net.c#L161

When you create something new, there's one lock on it already. The lock count is effectively the amount of pointers there are floating around.

Always on the 255th HTTP request

That's very interesting... If you compare the trace() between HTTP requests, what about the [r#l#] tags that get printed? In that case it sounds to me like the reference count has overflowed in that variable (so not jsvLock but jsvRef) - on 12 byte var systems it's a single byte.

Could you add an assert(jsvGetRefs(var)); line after:

https://github.com/espruino/Espruino/blob/master/src/jsvar.c#L566

.. so checking that adding 1 didn't cause the ref count to overflow.

Generally I haven't bothered checking for overflowed refs because the reffing only gets done internally and doesn't usually go wrong, but it could be that in this case something has gone wrong.

to me it looks like connection objects just don't get freed

It could be there's a circular reference - for instance the scope of a #ondata handler could reference an #onconnect call in which one of the parameters would be the connection object.

It'd mean it wasn't automatically freed, but a mark/sweep garbage collection pass (which happens when Espruino is idle or runs out of memory during execution) would realise and then free it.

---

Posted at 2015-12-17 by @gfwilliams

Strange about jspNewObject - I wonder whether that does cause an extra reference to get created somehow as you say?

I guess it's possible that on normal Espruino boards this doesn't get hit (often) because the reference count is 16 bit. If that's the case then recompiling on Linux with 1000 vars (as suggested above) might let you reproduce it. I'll give it a try.

---

Posted at 2015-12-17 by @allObjects

Is automatic memory management (acquire/release) done with just reference counting?

edit: no response needed... found what I looked for: mark/swep.

---

Posted at 2015-12-17 by @gfwilliams

Just reproduced it on PC :) I'll have a go at a fix - thanks for tracking this down...

---

Posted at 2015-12-17 by @gfwilliams

Is automatic memory management (acquire/release) done with just reference counting?

No... There's reference counting to free 99% of variables right away, but then it does a mark/sweep when idle or if it can't allocate any memory.

Ok, it's definitely an issue with references - see the r255 on the prototype here:

  #54[r1,l2] Name String [1 blocks] "httpCRq"    #55[r2,l1] NativeFunction 0x426706 (1) { 
      #56[r1,l2] Name String [2 blocks] "prototype"        #58[r255,l1] Object { 
          #59[r1,l2] Name String [2 blocks] "constructor"            #55[r2,l2] ...
 
        } 
    } 

It's being referenced a lot, but not unreferenced.

Looks like this could be a big issue with garbage collection, that when it frees things it isn't unreffing what they point to! I'll try and come up with some code to break it :)

---

Posted at 2015-12-17 by @gfwilliams

And yes, just broke it with:

var oops = "Hello";
for (var i=0;i<300;i++) {
  a = { };
  a.a = a;
  a.b = oops;
  a = undefined;
}

Wow, that's a huge bug! Really surprised that's existed for so long and we never noticed :)

---

Posted at 2015-12-17 by @gfwilliams

Ok, just fixed. Thanks @tve - that's a hugely important one to have found! Sorry it was such a pain to track down.

The issue was that the garbage collector would mark/sweep and would remove any vars it found that weren't referenced elsewhere. However, it assumed that once it found an object, that whole object would get removed so to do things quickly it just zeroed everything.

Unfortunately if that object referenced something that shouldn't get garbage collected, the reference count in that non-gc'd object wouldn't get decremented :(

In normal Espruino boards the reference count is 16 bits, and on Linux it's 32 bits, so most testing would never have hit it.

Having said that, a normal Espruino board doing any HTTP request would fail after 65536 requests - so at one request a second it still would have broken after 24 hours!

I'm actually kind of surprised about that because I've got an Espruino in the loft that's been doing HTTP requests every hour for months now - although I wonder whether we have enough power cuts here that it gets reset before there's a problem :)

---

Posted at 2015-12-17 by Ollie

@gfwilliams would this manifest itself just in HTTP or would anything dependent on sockets be impacted?

---

Posted at 2015-12-17 by @gfwilliams

I think anything using sockets - there are probably a few other cases where it could crop up too.

If you try http://www.espruino.com/binaries/git/commits/master/ now, those issues should be fixed though.

---

Posted at 2015-12-17 by @allObjects

Interesting, nice little caveat...

If mark/sweep is/was trumping reference count (which it should anyway), then (small) 'floating rings/clusters' have/would have 'gone after a while/with many marks and sweeps' anyway... but obviously, leaving other objects with incorrect reference count.

In your breaking example, did a got freed? ...and oops - even though global (I assume) - ended up with wrong reference count?

if a not global(ly reachable), it would go on a mark/sweep (when mark/sweep has precedence over reference count).

Early 90' when writing a oo vm in PL/1 on main pc for use on mainframe, I started out with reference counting... and it got pretty far... but only mark/sweep pulled true... so I abandoned reference count altogether (and would have lost the quick 99% freeing when memory would have been used with linked lists... ;-) ). Reference count was not even usable for validation/confirmation of freeing with single mark/sweep and multiples (I thought) I could not afford (next to the additional storage to remember that the last mark/sweep.

---

Posted at 2015-12-17 by @gfwilliams

Yes, a always got freed, and oops got the wrong reference count.

Because of the way Espruino works, there are a lot of small allocations. For example 1+2 allocates 1, 2 and finally 3. Sure, those could be freed without reference counting, but when objects are involved it gets virtually impossible without it.

What I really wanted to avoid was having code like this:

for (var i=0;i<1000;i++) {
  SPI1.send([1,2,3]);
}

That had to pause in the middle of execution to garbage collect all the copies of the array [1,2,3]. At the cost of some execution speed, Espruino generally manages to be more predictable when it does execute :)

---

Posted at 2015-12-17 by @gfwilliams

Having said that, I guess it might be an option to actually remove reference counting on really resource constrained devices - it'd reduce code size and memory usage, at the expense of having to run a gc pass more often.

---

Posted at 2015-12-17 by tve

Ok, just fixed. Thanks @tve - that's a hugely important one to have found! Sorry it was such a pain to track down.

Awesome, glad I produced enough chatter for you to realize where the issue was. ... and great fix turn-around! I'll give it a go later today.

---

Posted at 2015-12-17 by tve

It looks like the changes to JSvars make it impossible to upgrade a system that has something save()'ed? Notice how the names of variables are truncated:

>reset()
ASSERT(jsvHasChildren(parent)) FAILED AT src/jsvar.c:2116
  #1[r1,l2] Object {
    #2[r1,l2] Name String [1 blocks] "ÿ"      #3[r1,l2] Object {
        #6[r1,l2] Name String [2 blocks] "timer"          #8[r1,l1] Array(0) [ ]
        #9[r1,l2] Name String [2 blocks] "watche"          #11[r1,l1] Array(0) [ ]
        #14[r1,l2] Name String [1 blocks] "net"          #67[r1,l2] String [2 blocks] "\x04\x00\x00\x00\x00ÿÿÿ"
        #16[r1,l2] Name String [2 blocks] "histor"          #18[r1,l1] Array(5) [
            #19[r1,l2] Name Integer 0              #15[r1,l1] String [1 blocks] "dump()"
            #35[r1,l2] Name Integer 3              #48[r1,l1] String [6 blocks] "test_host=\"h.voeicken.cm\"; testport=456"
            #23[r1,l2] Name Integer 4              #25[r1,l1] String [1 blocks] "save()"
          ]
        #20[r1,l2] Name String [2 blocks] "module"          #61[r1,l1] Object {
            #36[r1,l2] Name String [1 blocks] "Wifi"              #62[r1,l1] NativeFunction 0x40214544 (0) { }
          }
        #70[r1,l2] Name String [2 blocks] "timers"          #72[r2,l1] Array(0) [ ]
        #73[r1,l2] Name String [2 blocks] "watches"          #75[r2,l1] Array(0) [ ]
        #91[r1,l2] Name String [2 blocks] "modules"          #96[r1,l1] Object {
            #104[r1,l2] Name String [1 blocks] "Wifi"              #97[r1,l1] NativeFunction 0x4020dcd4 (0) { }
          }
        #78[r1,l2] Name String [2 blocks] "except"          #108[r1,l1] Object {
            #106[r1,l2] Name String [2 blocks] "__proto__"              #87[r2,l1] ...
 
            #102[r1,l2] Name String [1 blocks] "msg"              #109[r1,l1] String [3 blocks] "Got ?[6] expected EOF"
            #79[r1,l2] Name String [1 blocks] "type"              #95[r1,l1] String [2 blocks] "SyntaxError"
          }
        #94[r1,l2] Name String [2 blocks] "sTrace"          #85[r1,l1] String [4 blocks] " at line 1 col 8\nreset()\n       ^\n"
      }
    #24[r1,l2] Name String [2 blocks] "test_hos"      #37[r1,l1] String [2 blocks] "h.voneicken.co"
    #31[r1,l2] Name String [2 blocks] "test_por"      #21[r1,l1] Integer 4567
    #56[r1,l2] Name String [3 blocks] "WifiEventDetil"      undefined
    #80[r1,l2] Name String [2 blocks] "SyntaxError"      #83[r2,l1] NativeFunction 0x4021a3a8 (9) {
        #84[r1,l2] Name String [2 blocks] "prototype"          #87[r2,l1] Object {
            #88[r1,l2] Name String [2 blocks] "constructor"              #83[r2,l2] ...
 
          }
      }
  }
REBOOTING!

---

Posted at 2015-12-17 by @gfwilliams

Oh, that'll be because the ordering of the enums changed when I added Native Strings.

To be honest that's always a problem - see the big red text at the bottom of http://www.espruino.com/Other+Boards

The Espruino bootloader blows away any saved code on upgrade. To be honest even if something like that enum doesn't stop it from working, because it stores pointers to functions inside native functions any update is likely to stop it working.

---

Posted at 2015-12-17 by tve

Sounds like there should be some version number embedded in the save()'ed stuff so it can be discarded when the number changes?

---

Posted at 2015-12-18 by @allObjects

Great explanation, and I thinks it - chaining small blocks - is a perfect compromise between contiguous bytes that need always a marks/sweep for memory reuse, even if declared as not-used/refd-anymore by refCount. I moved away from the refCount even though I had the unused memory peaces linked... but going always through the link and find an unused 'string' greater or equal the needs and re-link the remainder was not an option... last but not least because it would have challenged the virtual memory implementation...

In my memory manager (for MRAM/FRAM) I do though so but only limited: since only strings are used, I update as long as the string fits, and if shorter, it has to be short enough to also fit the linking for the remainder...

---

Posted at 2015-12-18 by tve

Well, the GC fix did the trick! My little test program is now past 10000 requests, including about 10 errored requests (it's wifi after all, I guess). So far I'm not seeing any memory leak and it hasn't gone kaboom either :-)

---

Posted at 2015-12-18 by @gfwilliams

Sounds like there should be some version number embedded in the save()'ed stuff so it can be discarded when the number changes?

Thing is it would have to change for every compile, since if the address of one function changes, that could mess the symbol table up. The chances of making a change where the addresses of all the functions stay the same is pretty small.

I guess you could just use the MD5sum of the binary as a version number, but IMO it's better to just delete the saved code each time you reflash.

... with the symbol table changes I had planned the situation might improve, but right now I'd suggest just erasing that block of memory.

---

Posted at 2015-12-19 by tve

Ah, this is something I haven't looked into at all... So where the saved code references native functions it contains the function's addresses? That would indeed be an issue...