Can't handle page with embedded images - Githubissues

marcoskirsch / nodemcu-httpserver

A (very) simple web server written in Lua for the ESP8266 firmware NodeMCU.

GNU General Public License v2.0

398 stars 166 forks source link

Can't handle page with embedded images #53

Closed marcoskirsch closed 4 years ago

marcoskirsch commented 8 years ago

The server quickly runs out of memory and crashes if a page with a few embedded images is requested. See example cars.html

  Requested URI: /cars.html
  Requested URI: /cars-mas.jpg
  Requested URI: /cars-ferrari.jpg
  Requested URI: /cars-lambo.jpg
  PANIC: unprotected error in call to Lua API (not enough memory)
  ����1�)m�1�)�!�����B

marcoskirsch commented 8 years ago

Well, sometimes it works.

devyte commented 8 years ago

it's a race condition. I understand that the ESP accepts up to 5 concurrent connections, and in the case of a webpage with elements, a browser may decide to request those elements concurrently. The httpserver mem footprint is rather large.

Serving one element is unlikely to make the ESP crash (unless it's a lua script being run, and it does something stupid). -Serving a second element concurrently means a second httpserver context. Currently, if the element is small, it may work, or if it's a second script, it will most likely crash. -I don't think a 3rd element will work, because 3 httpserver contexts don't fit in memory.

I see 2 possible solutions:

Limit the number of concurrent connections that the ESP accepts. This could be done by having a configuration option in the net module inside the firmware, or by implementing a kind of lock in the socket listening function. This solution may be ok for nodemcu-httpserver, but it would not be viable for my nodemcu-platform, so I would prefer to avoid it.
Reduce the mem footprint of the httpserver significantly. I would prefer to this be pursued, it would make for a better implementation.

marcoskirsch commented 8 years ago

A little more informative if I add a few prints for debugging. You can see the memory go down as expected until crash:

  GET: /cars.html
  Begin sending:    http/cars.html
  node.heap():  27216
  Sent: 713 of 713
  Finished sending:     http/cars.html
  GET: /cars-ferrari.jpg
  Begin sending:    http/cars-ferrari.jpg
  node.heap():  25008
  GET: /cars-lambo.jpg
  Begin sending:    http/cars-lambo.jpg
  node.heap():  16240
  GET: /cars-mas.jpg
  Begin sending:    http/cars-mas.jpg
  node.heap():  5776
  GET: /cars-porsche.jpg
  Begin sending:    http/cars-porsche.jpg
  node.heap():  2648
  Error:    not enough memory
  GET: /cars-mas.jpg
  Begin sending:    http/cars-mas.jpg
  node.heap():  2536
  PANIC: unprotected error in call to Lua API (not enough memory)
  ��I�x�1���Ό)����!��

Limit the number of concurrent connections that the ESP accepts.

Sounds like this won't happen in the short term based on the discussion at https://github.com/nodemcu/nodemcu-firmware/issues/1066

Reduce the mem footprint of the httpserver significantly.

This would be nice, but I doubt we can get that far. I'll check out the code and look for areas of improvement.

devyte commented 8 years ago

Ok, so a 3rd solution came up: buffer the incoming requests and process them serially. I have an implementation that allows this testcase to work, but it sometimes leaks memory, and I have no idea why yet.

ATAMAH commented 8 years ago

Right solution: load html page only with only <div> tags where must be images and load images serially by JS and insert into that divs.

Modern browsers always try to load page elements in many concurrent connections.

marcoskirsch commented 7 years ago

Latest code works with 3 images in cars.html... fourth image crashes the server. Could be due to running out of memory, limit in concurrent connections, or something else. More debugging needed.

ATAMAH commented 7 years ago

Fixed in my latest pull request.

You can add loading progress bar. Google "xhr.onprogress".

CharlesScoville commented 7 years ago

There appears to be more than just this issue with concurrent connections and nodemcu-httpserver.

Currently, if you have an html page that needs to run some script only once, it won't work right. The page gets requested by the browser up to a dozen times concurrently, so whatever init() you have gets run that many times. This includes any lua, since any call comes from the html, which is, again, loaded all those times. If you want to have any kind of initialization for a page, it seems you have to shoehorn it into the init.lua script.

Any one know what the deal with this is? Know a workaround that's better.

I've tried to use a semaphore in JavaScript and lua. And I've tried using the closure technique, or the window.onload method. Nothing has worked yet.

... I half suspect this may be a browser issue. Maybe I'll try with my lappy just to see.

Side Note: I'm actually fixing a GPIO bug in garage_door_opener, and this is being a problem. The GPIOs default to high when the system starts, they should default to gnd for garage_door_opener. I have code that does the trick for my ESP-01, but it only does GPIO0 and GPIO2, it's flaky for many more than two. (which I guess is fine for the demo case)

marcoskirsch commented 7 years ago

I'm actually fixing a GPIO bug in garage_door_opener, and this is being a problem. The GPIOs default to high when the system starts, they should default to gnd for garage_door_opener. I have code that does the trick for my ESP-01, but it only does GPIO0 and GPIO2, it's flaky for many more than two. (which I guess is fine for the demo case)

This depends on the how you have the hardware wired. I am using a Wemos D1 mini pro with their relay shield, and things work just fine. This is as "official" as it gets hardware-wise as far as I know, so I think it's fine to leave as is. It's an example after all. How I hated the ESP-01... you should give this Wemos thing a try.

HHHartmann commented 7 years ago

Another method would be to separate static content from dynamic content. The construct using the coroutine is very convenient for dynamic content generated by a lua script but it also has a large footprint. For just serving a file this is a huge overhead. Only the filename and the position has to be retained between sends. I have an implementation for that but need to sort out other changes before creating a PR.

Fractal147 commented 6 years ago

So I've had some ideas and done a variety of tests with cars.lua. I've got some findings: Different browsers make different patterns of requests, and behave differently with full refreshes and normal refreshes. The most aggressive I have found so far is mobile firefox on android, which submits all 6 image GET requests at once. Desktop Chrome often spreads out the GET requests, doing one first, then all the rest after the first has finished, but is more aggressive with a full refresh (ctrl-shift-r). server:listen won't give a callback beyond 5 sockets open, the 6th is either queued opaquely, or dropped. Sometimes the 6th will get triggered as soon as there's a connection freed up, but by that point it's usually out of memory!

Every incoming connection creates a new socket, with memory usage being considerable until the connection is closed. More memory is used once the httpserver processes the request, and then when it decides what to do with it - i.e. assigns a fileServeFunction, and again when a bufferedConnection is made. Peak memory usage is during a connection:send, for a full buffer, spiking at least 1.4 kB. This is usually the moment it generates an error.

I've had success with immediately processing a GET request to reduce it to just a URI, fileServefunction string, socket, and the args, then storing that in a table. This means the full headers are gc'd quickly. This can store all the image requests before serving them one-by-one - but there's still a httpserver instance per connection at several kB each. This has got cars.lua?n=6 to load repeatedly on desktop chrome, with free heap starting at 27 kB. Running memory usage can probably be reduced further by loading the httpserver-x modules with "require" and then removing them from the package.loaded table when finished with (httpserver-request will be my first candidate).

I'm in process of making these hacked together changes a bit more pushable - my project requires robust image handling, and more flexible delays, so it's going to happen!

HHHartmann commented 6 years ago

Just out of curiosity: what is the advantage of "require" and cleanup compared to dofile("")(params)

Fractal147 commented 6 years ago

Hi, I've got some documentation on them, and some tests with httpserver-request. The following docs somewhat cover the subject: 1.19 Difference between require and dofile? , nodemcu dev FAQ, and of course the lua 5.1 manual.

In terms of speed: Once loaded, require should be faster. When both unloaded, they should be similar, perhaps dofile has the edge. In terms of memory: Require can unload the memory used immediately afterwards. Dofile can't. There's also leakage, where they may behave differently. Other: Require automatically searches for the .lc extension first, then the .lua extension.

I've done some experiments on this, and it's actually gotten quite complicated! The summary is that dofile is pretty good, and probably best right at the moment, so my mistake! I suspect there's still savings to be had by changing the modules to be leaner.

I did a quick first test, confirming nodemcu-httpserver works when using require/unload in httpserver.lua for httpserver-request:

Straightforwards swap - low impact on memory

So for experimentation I've changed line 120 in httpserver.lua to ```lua local req = require("httpserver-request")(payload) package.loaded["httpserver-request"] = nil ``` I've even checked the function call to req.getRequestData() in http/post.lua still works after package has been unloaded. The concept of storing the header and the function to parse it should use more memory than just storing the parsed request data though. Everything still seems to work, but it's had no particular impact on memory! Memory measured by noting heap down when server:listen called. FOR DOFILE ```lua =node.heap() 34656 > NEW CONN, MEM IS 34456 192.168.0.51:64475 GET /cars.lua?n=4 192.168.0.51:64475 closing connection thread is dead NEW CONN, MEM IS 33832 192.168.0.51:64480 GET /cars-ferrari.jpg NEW CONN, MEM IS 27904 192.168.0.51:64481 GET /cars-lambo.jpg 192.168.0.51:64480 closing connection no (more) data CONN CLOSED, HEAP IS 24416 NEW CONN, MEM IS 27288 NEW CONN, MEM IS 26592 192.168.0.51:64481 closing connection no (more) data CONN CLOSED, HEAP IS 27512 192.168.0.51:64483 GET /cars-mas.jpg 192.168.0.51:64482 GET /cars-porsche.jpg 192.168.0.51:64483 closing connection no (more) data CONN CLOSED, HEAP IS 23536 192.168.0.51:64482 closing connection no (more) data CONN CLOSED, HEAP IS 28760 =node.heap() 33136 ``` FOR REQUIRE/UNLOAD ```lua =node.heap() 34616 > NEW CONN, MEM IS 34416 192.168.0.51:63882 GET /cars.lua?n=4 192.168.0.51:63882 closing connection thread is dead NEW CONN, MEM IS 33768 192.168.0.51:63883 GET /cars-ferrari.jpg NEW CONN, MEM IS 27448 NEW CONN, MEM IS 26696 192.168.0.51:63888 GET /cars-lambo.jpg 192.168.0.51:63889 GET /cars-mas.jpg 192.168.0.51:63889 closing connection no (more) data CONN CLOSED, HEAP IS 18944 192.168.0.51:63883 closing connection no (more) data CONN CLOSED, HEAP IS 24192 NEW CONN, MEM IS 26904 192.168.0.51:63890 GET /cars-porsche.jpg 192.168.0.51:63888 closing connection no (more) data CONN CLOSED, HEAP IS 23528 192.168.0.51:63890 closing connection no (more) data CONN CLOSED, HEAP IS 28768 =node.heap() 32704 ``` FOR REQUIRE ```lua =node.heap() 34664 > NEW CONN, MEM IS 34424 192.168.0.51:63497 GET /cars.lua?n=4 192.168.0.51:63497 closing connection thread is dead NEW CONN, MEM IS 27992 192.168.0.51:63498 GET /cars-ferrari.jpg NEW CONN, MEM IS 21264 NEW CONN, MEM IS 20536 NEW CONN, MEM IS 19872 192.168.0.51:63499 GET /cars-lambo.jpg 192.168.0.51:63501 GET /cars-porsche.jpg 192.168.0.51:63499 closing connection no (more) data CONN CLOSED, HEAP IS 11520 192.168.0.51:63501 closing connection no (more) data CONN CLOSED, HEAP IS 16552 192.168.0.51:63500 GET /cars-mas.jpg 192.168.0.51:63498 closing connection no (more) data CONN CLOSED, HEAP IS 17512 192.168.0.51:63500 closing connection no (more) data CONN CLOSED, HEAP IS 22832 =node.heap() 26928 ```

This is weird, so I played a bit with an artificial demo - given a request header, fill a table with 10 req's, then delete them one by one. I've compared three methods - dofile, require, and require+unload. I also timed how many times it could complete within 5 seconds, using node.task to schedule a new task. I finally made the httpserver-request run 50 times, and measured the memory leakage. dofile, and require+unload both use and release about 1700 bytes, apart from the first calling which takes and releases 2400 bytes. Require uses much more initially (~5k), but each subsequent call is 500 bytes. They all leak, but dofile and require+unload leak least.

Benchmark+results

Code

```lua function testFileMethods(variant) local testFile = "httpserver-request" local testHeaderFile = "exampleHeader.txt" exampleHeader = nil --variant is "dofile" "require" "require+unload" print(variant .. " chosen") if exampleHeader == nil then local fileSize = file.list()[testHeaderFile] local fileHandle = file.open(testHeaderFile) exampleHeader = fileHandle:read(fileSize) fileHandle:close() testHeaderFile=nil end --print(exampleHeader) collectgarbage() print("Filling 10 and unloading 10, heap at start is "..node.heap()) local reqTab={} local heapPrev = node.heap() collectgarbage() print("heap is before "..node.heap()) for n=1,10,1 do collectgarbage() heapPrev = node.heap() if variant == "dofile" then reqTab[n] = dofile(testFile..".lc")(exampleHeader) elseif variant == "require" then reqTab[n] = require(testFile)(exampleHeader) elseif variant == "require+unload" then reqTab[n] = require(testFile)(exampleHeader) package.loaded[testFile] = nil end collectgarbage() heapPrev = heapPrev - node.heap() print("heap is after "..n.." repeats "..node.heap().." with usage +" ..heapPrev) end collectgarbage() print("heap is with reqTab fully loaded "..node.heap()) for n=10,1,-1 do collectgarbage() heapPrev = node.heap() reqTab[n] = nil collectgarbage() heapPrev = heapPrev - node.heap() print("after popping line " ..n.." heap is "..node.heap().." saving "..heapPrev) heapPrev=node.heap() end if variant == "require" then package.loaded[testFile] = nil collectgarbage() print("after unloading package heap is " ..node.heap().." saving "..heapPrev) end collectgarbage() print("Finished 10 load/10 unload test, heap is " ..node.heap() ) collectgarbage() local req1= nil local timePrev=nil collectgarbage() heapPrev=node.heap() print("Starting 50 repeats, heap is " .. heapPrev) timePrev = tmr.time() for n=1, 50,1 do if variant == "dofile" then req1 = dofile(testFile..".lc")(exampleHeader) elseif variant == "require" then req1 = require(testFile)(exampleHeader) elseif variant == "require+unload" then req1 = require(testFile)(exampleHeader) package.loaded[testFile] = nil end end timePrev = tmr.time()-timePrev collectgarbage() if variant == "require" then print("About to unload package, heap is "..node.heap()) package.loaded[testFile] = nil collectgarbage() print("After unloading package heap is " ..node.heap()) end heapPrev = heapPrev - node.heap() print("50 repeats finished, heap is "..node.heap()..", gone down by ".. heapPrev) print("leak is about ".. heapPrev/50 .. " per load") print("time taken is about "..timePrev.." seconds") print("done "..variant) print("") end testFileMethods("dofile") testFileMethods("require+unload") testFileMethods("require") ```

dofile("df req benchmark.lua")
dofile chosen
Filling 10 and unloading 10, heap at start is 30240
heap is before 30240
heap is after 1 repeats 27008 with usage +3232
heap is after 2 repeats 25176 with usage +1832
heap is after 3 repeats 23872 with usage +1304
heap is after 4 repeats 22208 with usage +1664
heap is after 5 repeats 20520 with usage +1688
heap is after 6 repeats 18768 with usage +1752
heap is after 7 repeats 17096 with usage +1672
heap is after 8 repeats 15424 with usage +1672
heap is after 9 repeats 13744 with usage +1680
heap is after 10 repeats 12016 with usage +1728
heap is with reqTab fully loaded 12016
after popping line 10 heap is 13688 saving -1672
after popping line 9 heap is 15368 saving -1680
after popping line 8 heap is 17040 saving -1672
after popping line 7 heap is 18712 saving -1672
after popping line 6 heap is 20440 saving -1728
after popping line 5 heap is 22128 saving -1688
after popping line 4 heap is 23792 saving -1664
after popping line 3 heap is 25536 saving -1744
after popping line 2 heap is 27224 saving -1688
after popping line 1 heap is 29672 saving -2448
Finished 10 load/10 unload test, heap is 29672
Starting 50 repeats, heap is 29672
50 repeats finished, heap is 27176, gone down by 2496
leak is about 49 per load
time taken is about 4 seconds
done dofile

require+unload chosen
Filling 10 and unloading 10, heap at start is 29840
heap is before 29840
heap is after 1 repeats 27288 with usage +2552
heap is after 2 repeats 25600 with usage +1688
heap is after 3 repeats 23880 with usage +1720
heap is after 4 repeats 22152 with usage +1728
heap is after 5 repeats 20448 with usage +1704
heap is after 6 repeats 18720 with usage +1728
heap is after 7 repeats 17024 with usage +1696
heap is after 8 repeats 15352 with usage +1672
heap is after 9 repeats 13656 with usage +1696
heap is after 10 repeats 11912 with usage +1744
heap is with reqTab fully loaded 11912
after popping line 10 heap is 13608 saving -1696
after popping line 9 heap is 15304 saving -1696
after popping line 8 heap is 16976 saving -1672
after popping line 7 heap is 18672 saving -1696
after popping line 6 heap is 20352 saving -1680
after popping line 5 heap is 22056 saving -1704
after popping line 4 heap is 23784 saving -1728
after popping line 3 heap is 25488 saving -1704
after popping line 2 heap is 27176 saving -1688
after popping line 1 heap is 29616 saving -2440
Finished 10 load/10 unload test, heap is 29616
Starting 50 repeats, heap is 29616
50 repeats finished, heap is 27128, gone down by 2488
leak is about 49 per load
time taken is about 4 seconds
done require+unload

require chosen
Filling 10 and unloading 10, heap at start is 29800
heap is before 29800
heap is after 1 repeats 24248 with usage +5552
heap is after 2 repeats 23744 with usage +504
heap is after 3 repeats 23224 with usage +520
heap is after 4 repeats 22720 with usage +504
heap is after 5 repeats 22224 with usage +496
heap is after 6 repeats 21672 with usage +552
heap is after 7 repeats 21184 with usage +488
heap is after 8 repeats 20688 with usage +496
heap is after 9 repeats 20184 with usage +504
heap is after 10 repeats 19640 with usage +544
heap is with reqTab fully loaded 19640
after popping line 10 heap is 20136 saving -496
after popping line 9 heap is 20640 saving -504
after popping line 8 heap is 21136 saving -496
after popping line 7 heap is 21624 saving -488
after popping line 6 heap is 22128 saving -504
after popping line 5 heap is 22624 saving -496
after popping line 4 heap is 23128 saving -504
after popping line 3 heap is 23632 saving -504
after popping line 2 heap is 24136 saving -504
after popping line 1 heap is 24776 saving -640
after unloading package heap is 29632 saving 24672
Finished 10 load/10 unload test, heap is 29632
Starting 50 repeats, heap is 29632
About to unload package, heap is 24168
After unloading package heap is 27168
50 repeats finished, heap is 27072, gone down by 2560
leak is about 51 per load
time taken is about 2 seconds
done require