new httpServer loading many larger files fails

[piperpilot]

I'm having problems with the new httpServer implementation. My app loads about 7 different CS/JS files on the main page. Its inconsistent but at least one file fails to load. See the screenshot here:

Here is the debug output...you can see that connections are getting dropped and I'm not sure why.

onAccept state: 0 K=0
Free heap size=21776, K=0
+TCP connection
Opening connection. Total connections: 1
timeout updating: 70 -> 10
TcpServer onClient: 192.168.1.18

The headers are complete
attached file: index.html (3670 bytes)
TCP received: 425 bytes
READ Template (0)
plain template text pos: 0, len: 1024
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
READ Template (0)
found var: smobotversion, at 608 (1631) - 621, send size 607
Written: 607, Available: 607, isFinished: 0, PushCount: 2
READ Template (2)
StartVar smobotversion
Written: 2, Available: 2, isFinished: 0, PushCount: 3
READ Template (3)
continue to plaint text
plain template text pos: 1646, len: 1024
Written: 1024, Available: 1024, isFinished: 0, PushCount: 4
READ Template (0)
plain template text pos: 2670, len: 7
Written: 7, Available: 7, isFinished: 0, PushCount: 5
onReadyToSendData: 1
TCP sent: 2780
READ Template (0)
plain template text pos: 2677, len: 993
Written: 993, Available: 993, isFinished: 1, PushCount: 1
Body stream completed
onReadyToSendData: 2
TCP sent: 993
onReadyToSendData: 2
onAccept state: 0 K=1
Free heap size=17320, K=1
+TCP connection
Opening connection. Total connections: 2
timeout updating: 70 -> 10
TcpServer onClient: 192.168.1.18

The headers are complete
found bootstrap.css.gz
attached file: bootstrap.css.gz (15615 bytes)
TCP received: 383 bytes
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 537, Available: 537, isFinished: 0, PushCount: 3
onReadyToSendData: 1
onAccept state: 0 K=2
Free heap size=10848, K=2
+TCP connection
Opening connection. Total connections: 3
timeout updating: 70 -> 10
TcpServer onClient: 192.168.1.18

The headers are complete
found style.css
attached file: style.css (7384 bytes)
TCP received: 379 bytes
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 562, Available: 562, isFinished: 0, PushCount: 3
onReadyToSendData: 1

CONNECTION DROPPED
.(4712)

CONNECTION DROPPED
.(4928)

TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 732, Available: 732, isFinished: 0, PushCount: 3
onReadyToSendData: 2
TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 732, Available: 732, isFinished: 0, PushCount: 3
onReadyToSendData: 2
TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 732, Available: 732, isFinished: 0, PushCount: 3
onReadyToSendData: 2
TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 970, Available: 970, isFinished: 1, PushCount: 2
Body stream completed
onReadyToSendData: 2

CONNECTION DROPPED
.(5104)

TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 732, Available: 732, isFinished: 0, PushCount: 3
onReadyToSendData: 2
TCP sent: 1994
onReadyToSendData: 2
TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 732, Available: 732, isFinished: 0, PushCount: 3
onReadyToSendData: 2
onAccept state: 0 K=3
Free heap size=8264, K=3
+TCP connection
Opening connection. Total connections: 4
timeout updating: 70 -> 10
TcpServer onClient: 192.168.1.18

TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 886, Available: 886, isFinished: 1, PushCount: 2
Body stream completed
onReadyToSendData: 2
TCP sent: 1910
onReadyToSendData: 2
The headers are complete
found index.js
attached file: index.js (4378 bytes)
TCP received: 363 bytes
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 1024, Available: 1024, isFinished: 0, PushCount: 2
Written: 555, Available: 555, isFinished: 0, PushCount: 3
onReadyToSendData: 1
TCP sent: 2780
Written: 1024, Available: 1024, isFinished: 0, PushCount: 1
Written: 751, Available: 751, isFinished: 1, PushCount: 2
Body stream completed
onReadyToSendData: 2
TCP sent: 1775
onReadyToSendData: 2
TCP connection closed by timeout: 10 (from 10)
Closing connection. Total connections: 3
TCP connection closing
~TCP connection
-TCP connection
TCP connection closed by timeout: 10 (from 10)
Closing connection. Total connections: 2
TCP connection closing
~TCP connection
TCP connection closed by timeout: 10 (from 10)
Closing connection. Total connections: 1
TCP connection closing
~TCP connection
-TCP connection
-TCP connection
TCP connection closed by timeout: 10 (from 10)
Closing connection. Total connections: 0
TCP connection closing
~TCP connection
-TCP connection

[zgoda]

Does it fail if you combine all resources to single JS and CSS? If not, this may be related to memory usage per connection.

[slaff]

Issues that popped-up from my very fast analysis:

1. The TemplateFileStream does not report correctly its length. The original template length for index.html is 3670 bytes. There is one variable {smobotversion} that is replaced with data 98. Leading to -13 bytes difference. Which explains the following error curl: (18) transfer closed with 13 bytes remaining to read

2. Maybe in the case where you have multiple files it would be better to set the server timeout to 0. This way the used connections are closed as soon as possible.

[piperpilot]

@zgoda Its definately an option to combine to a fewer number of files, but that doesn't fix the problem. My exact number and size of files works just fine with the old httpServer before the refactor, so there seems to be a bug in the new server.

@slaff I'll try the server timeout change and look at the TemplateFileStream length and see if its something I can fix.

[slaff]

see if its something I can fix.

@piperpilot No need for that. Take a look at PR #1163 and try to use it. If you don't know how to do it here is a short help:

cd  $SMING_HOME
git fetch origin pull/1163/head:pr/1163
git checkout pr/1163
make dist-clean
make

And report the progress - should be better than before.

[piperpilot]

@slaff unfortunately that didn't fix anything. Still major failures on files.

[slaff]

@piperpilot I could not detect any (major) memory leak. What can be done though is:

1. Merge all CSS files into one CSS file and apply the same to the JS files.
2. In order for the closed TCP connections to be purged sooner than the default you can change the value TCP_MSL (in $SMING_HOME/third-party/esp-open-lwip/include/lwip/tcp_impl.h to something like 2000UL ), remove the old Sming and LWIP rilbaries

make -C $SMING_HOME/third-party/esp-open-lwip/ -f Makefile.open clean
rm $SMING_HOME/compiler/lib/liblwip*.a
rm $SMING_HOME/compile/lib/libsming*.a

and recompile your project.

3. Make sure that you have compiler has support for the mforce-l32 flag. To check this run the following command
   xtensa-lx106-elf-gcc --help=target | grep mforce-l32 and see if something comes as output.

4. What we can also add it better HTTP client side cache support with the help of Expires and ETag headers. (So that the browser loads the CSS/JS file(s) once and keeps them in its cache for a week or more.

[piperpilot]

@slaff

#1 seems like a bandaid. This exact same JS/CSS worked fine in previous versions of SMING before the re-write of the client/server.

#2 I will try this and see if it helps.

#3 I verified taht my compiler, esp-alt-sdk does NOT have the mforce-l32 so I am downloading and rebuilding the esp-open-sdk. Maybe that is the root of my problem.

#4 part of the issue is that the client doesn't even get the files the first time so they can't be cached. Maybe if on a 2nd reload it only has to request the failed files, then that would work, but its a poor experience for the users that the first time they use a browser it would fail to load the page. Again this is a bandaid to fix the problem.

I will report back on the results of #3 and then #2 above and see if that helps. If the mforce-l32 support is required, we should probably either get the esp-alt-sdk fixed to support it, or drop support for that toolchain.

Thanks for all of your work on the project lately. When it comes to the memory management, I"m kind of lost.

[slaff]

Closing due to inactivity. Feel free to reopen it if the issue is still present in the latest develop version.