khoih-prog / EthernetWebServer

This is simple yet complete WebServer library for AVR, AVR Dx, Portenta_H7, Teensy, SAM DUE, SAMD21/SAMD51, nRF52, STM32, RP2040-based, etc. boards running Ethernet shields. The functions are similar and compatible to ESP8266/ESP32 WebServer libraries to make life much easier to port sketches from ESP8266/ESP32. Coexisting now with `ESP32 WebServer` and `ESP8266 ESP8266WebServer` libraries. Ethernet_Generic library is used as default for W5x00 with custom SPI
MIT License
178 stars 49 forks source link

Consecutive page refreshes finally leads to data corruption and Connection Refused #38

Closed aagiannidis closed 2 years ago

aagiannidis commented 2 years ago

Dear all, first of all i need to congratulate you on this wonderful library. I dont want to waste anyones time but I am desperate to find a solution. I can see that this topic is somehow similar to a previous one but I am confident that it is a valid case to be examined.

I am using an arduino Mega with an ethernet shield 2. The device is powered from USB cable directly connected to laptop. I have developed my own program and came across some issues that I couldnt explain. Finally i went back to the drawing board and conducted my tests with the Simple Authentication example as provided. I could replicate the issues with this example so it makes me think there is a bug somewhere in the library.

The bug is as follows: after consecutive refreshes the arduino starts sending less and less data and finally i get the message connection refused on the browser. The arduino seems to be stuck as it produces nothing. However it responds to pings Ok.

Here is some info on how to replicate the bug:

Arduino 1.8.13 Arduino Mega plus Ethernet Shield 2 featuring a W5500. Example: Simple Authentication Page to refresh: $IP ADDRESS$/login Browser: Chrome and Firefox Configuration settings: using either Ethernet or Ethernet2 library

Load the page and do about 200 refreshes. Refreshes should be done once the page is loaded. On every refresh the arduino should send 350 characters with the content

<html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br>Password:<input type='password' name='PASSWORD' placeholder='password'><br><input type='submit' name='SUBMIT' value='Submit'></form><br>You also can go <a href='/inline'>here</a></body></html>

After 150-200 refreshes the arduino starts sending less and less characters. Please see provided log further down.

Also, if the refreshes are faster the arduino will also report corrupted data on its parsed received headers. Please see provided log further down.

Here is a perfect page refresh log that sends the full 350 character long web page:

13:03:10.270 -> [EWS] handleClient: New Client
13:03:10.304 -> [EWS] method:  GET
13:03:10.304 -> [EWS] url:  /login
13:03:10.304 -> [EWS] search:  
13:03:10.304 -> [EWS] headerName: Host
13:03:10.304 -> [EWS] headerValue: 192.168.1.30
13:03:10.304 -> [EWS] headerName: Connection
13:03:10.304 -> [EWS] headerValue: keep-alive
13:03:10.304 -> [EWS] headerName: Upgrade-Insecure-Requests
13:03:10.338 -> [EWS] headerValue: 1
13:03:10.372 -> [EWS] headerName: User-Agent
13:03:10.372 -> [EWS] headerValue: Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.69 Safari/537.36
13:03:10.406 -> [EWS] headerName: Accept
13:03:10.406 -> [EWS] headerValue: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.9
13:03:10.440 -> [EWS] headerName: Accept-Encoding
13:03:10.440 -> [EWS] headerValue: gzip, deflate
13:03:10.440 -> [EWS] headerName: Accept-Language
13:03:10.474 -> [EWS] headerValue: en-US,en;q=0.9,el;q=0.8
13:03:10.474 -> [EWS] headerName: Cookie
13:03:10.474 -> [EWS] headerValue: ESPSESSIONID=0
13:03:10.474 -> [EWS] args:  
13:03:10.474 -> [EWS] args count:  0
13:03:10.474 -> [EWS] args:  
13:03:10.474 -> [EWS] args count:  0
13:03:10.474 -> [EWS] Request: /login
13:03:10.474 -> [EWS] Arguments: 
13:03:10.474 -> [EWS] Final list of key/value pairs:
13:03:10.474 -> [EWS] _handleRequest handle
13:03:10.474 -> Found cookie: ESPSESSIONID=0
13:03:10.474 -> [EWS] send1: len =  350
13:03:10.507 -> [EWS] content =  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br>Password:<input type='password' name='PASSWORD' placeholder='password'><br><input type='submit' name='SUBMIT' value='Submit'></form><br>You also can go <a href='/inline'>here</a></body></html>
13:03:10.541 -> [EWS] _prepareHeader sendHeader Conn close
13:03:10.541 -> [EWS] send1: write header =  HTTP/1.1 200 OK
13:03:10.541 -> Content-Type: text/html
13:03:10.541 -> Content-Length: 350
13:03:10.541 -> Connection: close
13:03:10.541 -> 
13:03:10.541 -> 
13:03:10.541 -> [EWS] sendContent: Client.write content:  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br>Password:<input type='password' name='PASSWORD' placeholder='password'><br><input type='submit' name='SUBMIT' value='Submit'></form><br>You also can go <a href='/inline'>here</a></body></html>
13:03:10.576 -> [EWS] _handleRequest OK
13:03:10.576 -> [EWS] handleClient: Don't keepCurrentClient

After 150-200 refreshes it sends less data. In this case it sends 237 characters only.

13:09:09.095 -> [EWS] handleClient: New Client
13:09:09.129 -> [EWS] method:  GET
13:09:09.129 -> [EWS] url:  /login
13:09:09.129 -> [EWS] search:  
13:09:09.129 -> [EWS] headerName: Host
13:09:09.129 -> [EWS] headerValue: 192.168.1.30
13:09:09.129 -> [EWS] headerName: Connection
13:09:09.129 -> [EWS] headerValue: keep-alive
13:09:09.129 -> [EWS] headerName: Cache-Control
13:09:09.129 -> [EWS] headerValue: max-age=0
13:09:09.163 -> [EWS] headerName: Upgrade-Insecure-Requests
13:09:09.163 -> [EWS] headerValue: 1
13:09:09.197 -> [EWS] headerName: User-Agent
13:09:09.197 -> [EWS] headerValue: 
13:09:09.231 -> [EWS] headerName: Accept
13:09:09.231 -> [EWS] headerValue: text/html,application/xhtml+
13:09:09.264 -> [EWS] headerName: Accept-Encoding
13:09:09.264 -> [EWS] headerValue: gzip, deflate
13:09:09.264 -> [EWS] headerName: Accept-Language
13:09:09.264 -> [EWS] headerValue: en-US,en;q=0.9,el;q
13:09:09.264 -> [EWS] headerName: Cookie
13:09:09.299 -> [EWS] headerValue: ESPSESSIONID=0
13:09:09.299 -> [EWS] args:  
13:09:09.299 -> [EWS] args count:  0
13:09:09.299 -> [EWS] args:  
13:09:09.299 -> [EWS] args count:  0
13:09:09.299 -> [EWS] Request: /login
13:09:09.299 -> [EWS] Arguments: 
13:09:09.299 -> [EWS] Final list of key/value pairs:
13:09:09.299 -> [EWS] _handleRequest handle
13:09:09.299 -> Found cookie: ESPSESSIONID=0
13:09:09.299 -> [EWS] send1: len =  237
13:09:09.299 -> [EWS] content =  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br>Password:<input type='password' name='PASSWORD' placeholder='password'><br><br>
13:09:09.335 -> [EWS] _prepareHeader sendHeader Conn close
13:09:09.335 -> [EWS] send1: write header =  HTTP/1.1 200 OK
13:09:09.335 -> Content-Type: text/html
13:09:09.335 -> Content-Length: 237
13:09:09.335 -> 
13:09:09.335 -> 
13:09:09.335 -> [EWS] sendContent: Client.write content:  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br>Password:<input type='password' name='PASSWORD' placeholder='password'><br><br>
13:09:09.367 -> [EWS] _handleRequest OK
13:09:10.347 -> [EWS] handleClient: Don't keepCurrentClient

After a few more refreshes it sends 90 characters

13:12:08.727 -> [EWS] handleClient: New Client
13:12:08.727 -> [EWS] method:  GET
13:12:08.727 -> [EWS] url:  /login
13:12:08.727 -> [EWS] search:  
13:12:08.727 -> [EWS] headerName: Host
13:12:08.727 -> [EWS] headerValue: 192.168.1.30
13:12:08.760 -> [EWS] headerName: Connection
13:12:08.760 -> [EWS] headerValue: keep-alive
13:12:08.760 -> [EWS] headerName: Cache-Control
13:12:08.760 -> [EWS] headerValue: max-age=0
13:12:08.760 -> [EWS] headerName: Upgrade-Insecure-Requests
13:12:08.760 -> [EWS] headerValue: 1
13:12:08.794 -> [EWS] headerName: User-Agent
13:12:08.828 -> [EWS] headerValue: Mozilla/5.0 (Windows NT 6.1; Win
13:12:08.862 -> [EWS] headerName: Accept
13:12:08.862 -> [EWS] headerValue: text/html,ap
13:12:08.862 -> [EWS] headerName: Accept-Encoding
13:12:08.862 -> [EWS] headerValue: gzi
13:12:08.896 -> [EWS] headerName: Accept-Language
13:12:08.896 -> [EWS] headerValue: en-
13:12:08.896 -> [EWS] headerName: Cookie
13:12:08.896 -> [EWS] headerValue: ESPSESSIONID
13:12:08.896 -> [EWS] args:  
13:12:08.896 -> [EWS] args count:  0
13:12:08.896 -> [EWS] args:  
13:12:08.896 -> [EWS] args count:  0
13:12:08.896 -> [EWS] Request: /login
13:12:08.896 -> [EWS] Arguments: 
13:12:08.896 -> [EWS] Final list of key/value pairs:
13:12:08.930 -> [EWS] _handleRequest handle
13:12:08.930 -> Found cookie: ESPSESSIONID
13:12:08.930 -> [EWS] send1: len =  90
13:12:08.930 -> [EWS] content =  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>
13:12:08.930 -> [EWS] _prepareHeader sendHeader Conn close
13:12:08.930 -> [EWS] send1: write header =  HTTP/1.1 200 OK
13:12:08.930 -> Content-Length: 90
13:12:08.930 -> 
13:12:08.930 -> 
13:12:08.930 -> [EWS] sendContent: Client.write content:  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>
13:12:08.963 -> [EWS] _handleRequest OK
13:12:09.942 -> [EWS] handleClient: Don't keepCurrentClient

And eventually you get the ERR_CONNECTION_REFUSED from the browser. The arduino at this point seems to be stuck as it does not produce and logs but weirdly it responds to pings Ok.

image

image

Finally, when someone goes crazy with the page refresh and keeps refreshing very fast, i can see corrupted data on the headers too...See below (please note how the ip address is not correctly filled in):

22:08:19.519 -> [EWS] handleClient: New Client
22:08:19.519 -> [EWS] method:  GET
22:08:19.519 -> [EWS] url:  /login
22:08:19.519 -> [EWS] search:  
22:08:19.519 -> [EWS] headerName: Host
22:08:19.519 -> [EWS] headerValue: 192.168.1.
22:08:19.519 -> [EWS] args:  
22:08:19.519 -> [EWS] args count:  0
22:08:19.519 -> [EWS] args:  
22:08:19.519 -> [EWS] args count:  0
22:08:19.519 -> [EWS] Request: /login
22:08:19.519 -> [EWS] Arguments: 
22:08:19.554 -> [EWS] Final list of key/value pairs:
22:08:19.554 -> [EWS] _handleRequest handle
22:08:19.554 -> [EWS] send1: len =  68
22:08:19.554 -> [EWS] content =  User:<input type='text' name='USERNAME' placeholder='user name'><br>
22:08:19.554 -> [EWS] _prepareHeader sendHeader Conn close
22:08:19.554 -> [EWS] send1: write header =   
22:08:19.554 -> 
22:08:19.554 -> [EWS] sendContent: Client.write content:  User:<input type='text' name='USERNAME' placeholder='user name'><br>
22:08:19.554 -> [EWS] _handleRequest OK
22:08:19.589 -> [EWS] handleClient: Don't keepCurrentClient

and also some funny log that shows things really messed up

22:08:20.978 -> [EWS] handleClient: New Client
22:08:20.978 -> [EWS] method:  GET
22:08:20.978 -> [EWS] url:  /login
22:08:20.978 -> [EWS] search:  
22:08:20.978 -> [EWS] args:  
22:08:20.978 -> [EWS] args count:  0
22:08:20.978 -> [EWS] args:  
22:08:20.978 -> [EWS] args count:  0
22:08:21.012 -> [EWS] Request: /login
22:08:21.012 -> [EWS] Arguments: 
22:08:21.012 -> [EWS] Final list of key/value pairs:
22:08:21.012 -> [EWS] _handleRequest: request handler not found
22:08:21.012 -> [EWS] send1: len =  53
22:08:21.012 -> [EWS] content =  File Not Found
22:08:21.012 -> 
22:08:21.012 -> URI: /login
22:08:21.012 -> Method: GET
22:08:21.012 -> Arguments: 0
22:08:21.012 -> 
22:08:21.012 -> [EWS] _prepareHeader sendHeader Conn close
22:08:21.012 -> [EWS] send1: write header =   404 
22:08:21.012 -> 
22:08:21.012 -> 
22:08:21.012 -> [EWS] sendContent: Client.write content:  File Not Found
22:08:21.012 -> 
22:08:21.012 -> URI: /login
22:08:21.012 -> Method: GET
22:08:21.012 -> Arguments: 0
22:08:21.012 -> 
22:08:21.012 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.657 -> [EWS] handleClient: New Client
22:08:21.657 -> [EWS] _parseRequest: Invalid request:  GET /l
22:08:21.691 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.691 -> [EWS] handleClient: New Client
22:08:21.691 -> [EWS] _parseRequest: Invalid request:  Host: 
22:08:21.691 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.691 -> [EWS] handleClient: New Client
22:08:21.691 -> [EWS] _parseRequest: Invalid request:  Connec
22:08:21.691 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.691 -> [EWS] handleClient: New Client
22:08:21.725 -> [EWS] _parseRequest: Invalid request:  Cache-
22:08:21.725 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.725 -> [EWS] handleClient: New Client
22:08:21.725 -> [EWS] _parseRequest: Invalid request:  Upgrad
22:08:21.725 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.725 -> [EWS] handleClient: New Client
22:08:21.759 -> [EWS] _parseRequest: Invalid request:  User-A
22:08:21.759 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.793 -> [EWS] handleClient: New Client
22:08:21.827 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:21.827 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.827 -> [EWS] handleClient: New Client
22:08:21.827 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:21.827 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.827 -> [EWS] handleClient: New Client
22:08:21.861 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:21.861 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.861 -> [EWS] handleClient: New Client
22:08:21.861 -> [EWS] _parseRequest: Invalid request:  Cookie
22:08:21.861 -> [EWS] handleClient: Don't keepCurrentClient
22:08:21.861 -> [EWS] handleClient: New Client
22:08:21.894 -> [EWS] _parseRequest: Invalid request:  
22:08:21.894 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.176 -> [EWS] handleClient: New Client
22:08:23.176 -> [EWS] _parseRequest: Invalid request:  GET /l
22:08:23.176 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.176 -> [EWS] handleClient: New Client
22:08:23.176 -> [EWS] _parseRequest: Invalid request:  Host: 
22:08:23.209 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.209 -> [EWS] handleClient: New Client
22:08:23.209 -> [EWS] _parseRequest: Invalid request:  Connec
22:08:23.209 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.209 -> [EWS] handleClient: New Client
22:08:23.209 -> [EWS] _parseRequest: Invalid request:  Cache-
22:08:23.209 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.209 -> [EWS] handleClient: New Client
22:08:23.243 -> [EWS] _parseRequest: Invalid request:  Upgrad
22:08:23.243 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.243 -> [EWS] handleClient: New Client
22:08:23.276 -> [EWS] _parseRequest: Invalid request:  User-A
22:08:23.276 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.276 -> [EWS] handleClient: New Client
22:08:23.344 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:23.344 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.344 -> [EWS] handleClient: New Client
22:08:23.344 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:23.344 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.344 -> [EWS] handleClient: New Client
22:08:23.378 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:23.378 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.378 -> [EWS] handleClient: New Client
22:08:23.378 -> [EWS] _parseRequest: Invalid request:  Cookie
22:08:23.378 -> [EWS] handleClient: Don't keepCurrentClient
22:08:23.378 -> [EWS] handleClient: New Client
22:08:23.378 -> [EWS] _parseRequest: Invalid request:  
22:08:23.378 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.002 -> [EWS] handleClient: New Client
22:08:25.002 -> [EWS] _parseRequest: Invalid request:  GET /l
22:08:25.002 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.002 -> [EWS] handleClient: New Client
22:08:25.002 -> [EWS] _parseRequest: Invalid request:  Host: 
22:08:25.002 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.002 -> [EWS] handleClient: New Client
22:08:25.002 -> [EWS] _parseRequest: Invalid request:  Connec
22:08:25.036 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.036 -> [EWS] handleClient: New Client
22:08:25.036 -> [EWS] _parseRequest: Invalid request:  Cache-
22:08:25.036 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.036 -> [EWS] handleClient: New Client
22:08:25.036 -> [EWS] _parseRequest: Invalid request:  Upgrad
22:08:25.071 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.071 -> [EWS] handleClient: New Client
22:08:25.104 -> [EWS] _parseRequest: Invalid request:  User-A
22:08:25.104 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.104 -> [EWS] handleClient: New Client
22:08:25.139 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:25.139 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.139 -> [EWS] handleClient: New Client
22:08:25.171 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:25.171 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.171 -> [EWS] handleClient: New Client
22:08:25.171 -> [EWS] _parseRequest: Invalid request:  Accept
22:08:25.171 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.171 -> [EWS] handleClient: New Client
22:08:25.205 -> [EWS] _parseRequest: Invalid request:  Cookie
22:08:25.205 -> [EWS] handleClient: Don't keepCurrentClient
22:08:25.205 -> [EWS] handleClient: New Client
22:08:25.205 -> [EWS] _parseRequest: Invalid request:  
22:08:25.205 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.215 -> [EWS] handleClient: New Client
22:09:28.215 -> [EWS] _parseRequest: Invalid request:  GET /l
22:09:28.248 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.248 -> [EWS] handleClient: New Client
22:09:28.248 -> [EWS] _parseRequest: Invalid request:  Host: 
22:09:28.248 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.248 -> [EWS] handleClient: New Client
22:09:28.248 -> [EWS] _parseRequest: Invalid request:  Connec
22:09:28.248 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.248 -> [EWS] handleClient: New Client
22:09:28.282 -> [EWS] _parseRequest: Invalid request:  Cache-
22:09:28.282 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.282 -> [EWS] handleClient: New Client
22:09:28.282 -> [EWS] _parseRequest: Invalid request:  Upgrad
22:09:28.282 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.282 -> [EWS] handleClient: New Client
22:09:28.316 -> [EWS] _parseRequest: Invalid request:  User-A
22:09:28.350 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.350 -> [EWS] handleClient: New Client
22:09:28.384 -> [EWS] _parseRequest: Invalid request:  Accept
22:09:28.384 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.384 -> [EWS] handleClient: New Client
22:09:28.384 -> [EWS] _parseRequest: Invalid request:  Accept
22:09:28.384 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.418 -> [EWS] handleClient: New Client
22:09:28.418 -> [EWS] _parseRequest: Invalid request:  Accept
22:09:28.418 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.418 -> [EWS] handleClient: New Client
22:09:28.418 -> [EWS] _parseRequest: Invalid request:  Cookie
22:09:28.418 -> [EWS] handleClient: Don't keepCurrentClient
22:09:28.452 -> [EWS] handleClient: New Client
22:09:28.452 -> [EWS] _parseRequest: Invalid request:  
22:09:28.452 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.143 -> [EWS] handleClient: New Client
22:09:32.143 -> [EWS] _parseRequest: Invalid request:  GET /l
22:09:32.143 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.143 -> [EWS] handleClient: New Client
22:09:32.143 -> [EWS] _parseRequest: Invalid request:  Host: 
22:09:32.177 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.177 -> [EWS] handleClient: New Client
22:09:32.177 -> [EWS] _parseRequest: Invalid request:  Connec
22:09:32.177 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.177 -> [EWS] handleClient: New Client
22:09:32.177 -> [EWS] _parseRequest: Invalid request:  Cache-
22:09:32.177 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.177 -> [EWS] handleClient: New Client
22:09:32.211 -> [EWS] _parseRequest: Invalid request:  Upgrad
22:09:32.211 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.211 -> [EWS] handleClient: New Client
22:09:32.245 -> [EWS] _parseRequest: Invalid request:  User-A
22:09:32.245 -> [EWS] handleClient: Don't keepCurrentClient
22:09:32.245 -> [EWS] handleClient: New Client
aagiannidis commented 2 years ago

Just before the arduino becomes non-responsive i can see from the logs that prepareHeader is executing but the send function is not executed.

16:54:55.123 -> [EWS] handleClient: New Client
16:54:55.157 -> [EWS] method:  GET
16:54:55.157 -> [EWS] url:  /login
16:54:55.157 -> [EWS] search:  
16:54:55.157 -> [EWS] headerName: Host
16:54:55.157 -> [EWS] headerValue: 192.168.1.30
16:54:55.157 -> [EWS] headerName: Connection
16:54:55.157 -> [EWS] headerValue: keep-alive
16:54:55.157 -> [EWS] headerName: Cache-Control
16:54:55.157 -> [EWS] headerValue: max-age=0
16:54:55.190 -> [EWS] args:  
16:54:55.190 -> [EWS] args count:  0
16:54:55.190 -> [EWS] args:  
16:54:55.190 -> [EWS] args count:  0
16:54:55.190 -> [EWS] Request: /login
16:54:55.190 -> [EWS] Arguments: 
16:54:55.190 -> [EWS] Final list of key/value pairs:
16:54:55.190 -> [EWS] _handleRequest handle
16:54:55.190 -> [EWS] send1: len =  162
16:54:55.190 -> [EWS] content =  <html><body><form action='/login' method='POST'>To log in, please use : admin/password<br>User:<input type='text' name='USERNAME' placeholder='user name'><br><br
16:54:55.224 -> [EWS] _prepareHeader sendHeader Conn close

This bit is missing from the log (taken from full ok example above)

22:08:19.554 -> [EWS] send1: write header =   
22:08:19.554 -> 
22:08:19.554 -> [EWS] sendContent: Client.write content:  User:<input type='text' name='USERNAME' placeholder='user name'><br>
22:08:19.554 -> [EWS] _handleRequest OK
22:08:19.589 -> [EWS] handleClient: Don't keepCurrentClient

I think the problem occurs in this function

void EthernetWebServer::send(int code, const char* content_type, const String& content) 
{
  String header;

  // Can we asume the following?
  //if(code == 200 && content.length() == 0 && _contentLength == CONTENT_LENGTH_NOT_SET)
  //  _contentLength = CONTENT_LENGTH_UNKNOWN;

  ET_LOGDEBUG1(F("send1: len = "), content.length());
  ET_LOGDEBUG1(F("content = "), content);

  _prepareHeader(header, code, content_type, content.length());

  _currentClient.write((const uint8_t *)header.c_str(), header.length());

  if (content.length())
  {
    ET_LOGDEBUG1(F("send1: write header = "), header);
    //sendContent(content);
    sendContent(content, content.length());
  }  
}
aagiannidis commented 2 years ago

Also a malformed log before Chrome says Err Connection Refused. Note how the header values are malformed.

17:12:00.600 -> [EWS] handleClient: New Client
17:12:00.600 -> [EWS] method:  GET
17:12:00.600 -> [EWS] url:  /login
17:12:00.600 -> [EWS] search:  
17:12:00.600 -> [EWS] headerName: Host
17:12:00.600 -> [EWS] headerValue: 192.168.1.30
17:12:00.600 -> [EWS] headerName: Connection
17:12:00.600 -> [EWS] headerValue: keep-alive
17:12:00.600 -> [EWS] headerName: Cache-Control
17:12:00.634 -> [EWS] headerValue: max-age=0
17:12:00.634 -> [EWS] headerName: Upgrade-Insecure-Requests
17:12:00.634 -> [EWS] headerValue: 1
17:12:00.668 -> [EWS] headerName: User-Agent
17:12:00.668 -> [EWS] headerValue: Mozilla/5.0 (Windows NT 6.1; Win
17:12:00.737 -> [EWS] headerName: Accept
17:12:00.737 -> [EWS] headerValue: text/html,ap
17:12:00.737 -> [EWS] headerName: Accept-Encoding
17:12:00.737 -> [EWS] headerValue: gzi
17:12:00.737 -> [EWS] headerName: Accept-Language
17:12:00.737 -> [EWS] headerValue: en-
17:12:00.737 -> [EWS] headerName: Cookie
17:12:00.771 -> [EWS] headerValue: ESPSESSIONID
17:12:00.771 -> [EWS] args:  
17:12:00.771 -> [EWS] args count:  0
17:12:00.771 -> [EWS] args:  
17:12:00.771 -> [EWS] args count:  0
17:12:00.771 -> [EWS] Request: /
aagiannidis commented 2 years ago

Hi all,

using the simple authentication example with the addition of the MemoryUsage library to show memory stats, one can see that over successive page reloads the memory heap is being exhausted...bringing everything to a stall..

19:23:41.443 -> Stack start:8670
19:23:41.443 -> Stack end:8703
19:23:41.443 -> Stack size:33
19:23:41.443 -> Data start:512
19:23:41.443 -> Heap start:3055
19:23:41.443 -> Heap end:4003

19:24:35.899 -> Stack start:8670
19:24:35.899 -> Stack end:8703
19:24:35.899 -> Stack size:33
19:24:35.899 -> Data start:512
19:24:35.899 -> Heap start:3055
19:24:35.899 -> Heap end:5186

19:25:43.502 -> Stack start:8670
19:25:43.502 -> Stack end:8703
19:25:43.502 -> Stack size:33
19:25:43.502 -> Data start:512
19:25:43.502 -> Heap start:3055
19:25:43.502 -> Heap end:7177

19:26:32.209 -> Stack start:8670
19:26:32.209 -> Stack end:8703
19:26:32.209 -> Stack size:33
19:26:32.209 -> Data start:512
19:26:32.209 -> Heap start:3055
19:26:32.209 -> Heap end:8122

19:27:05.778 -> Stack start:8670
19:27:05.778 -> Stack end:8703
19:27:05.778 -> Stack size:33
19:27:05.778 -> Data start:512
19:27:05.778 -> Heap start:3055
19:27:05.778 -> Heap end:8417
khoih-prog commented 2 years ago

Hi @aagiannidis

Thanks for your interests and nice words about the library.

I'm amazed that you've spent lots of time to investigate the issue. But my feeling is that you're using the worst board for the job (Mega with only 16MHz, 8KB of RAM) which can create problems (heap corruption, not enough memory, etc.) in real-time and it's very time-consuming and not worthy to spend time to investigate and solve the issue

As you know, this library also relies on so many underlying libraries / core (Ethernet library, AVR core, etc) , so any bug can also cause the issue.

I suggest you use a better board for the demanding job, such as ESP32 / ESP8266 / Nano_RP2040_Connect for WiFi, or WT32_ETH01 for Ethernet (using WebServer_WT32_ETH01 library), and finally find out it's much more economical to use them as our time is much more precious.

Also have a look at Arduino hangs after repeated refreshing #8 and understand that using wrong board, with less memory, slow, etc., can create big headache

I'm sorry I have to close the issue, and won't spend time on this, even this is the real issue on the antique Mega board.

Good Luck,