esp8266 / Arduino

ESP8266 core for Arduino
GNU Lesser General Public License v2.1
16.06k stars 13.33k forks source link

Response lag if ESP was idle #4332

Open s0170071 opened 6 years ago

s0170071 commented 6 years ago

I am using the sketch from https://github.com/esp8266/Arduino/issues/3871 with a Wemos D1 mini and core 2.4.0 The webpage from the example usually loads swiftly within 74 ms. Repeatedly. If I let the ESP alone for about 2 minutes, it does not respond at first. Webpage load then takes 7-15s. After that its back to 74ms.

d-a-v commented 6 years ago

If you are running git master version of the core, a dump of the traffic is welcome (wireshark, tcpdump).

s0170071 commented 6 years ago

hers is a debug dump. I split it into two parts, after power up and after I accessed the ESP via browser. To me it looks like it (or the router) is dropping the connection. Edit: its the serial output of my ESPEasy , not the example sketch. Please ignore all output that starts like "xxx : "


csum 0x2d
v4ceabea9
~ld
⸮U

INIT : Booting version: (custom)
INIT : Warm boot #26
FS   : Mounting...
FS   : Mount successful, used 75802 bytes of 957314
CRC  : program checksum       ...OK
CRC  : Settings CRC           ...OK
CRC  : binary has changed since last save of Settings
CRC  : SecuritySettings CRC   ...OK 
CRC  : binary has changed since last save of Settings
INIT : Free RAM:17776
INIT : I2C
INIT : SPI not enabled
WIFI : AP Mode disabled
WIFI : AP Mode ssid will be ESP_Easy_0 with address 192.168.4.1
WIFI : Connecting MNET attempt #1
wifi evt: 8
wifi evt: 2
wifi evt: 0
wifi evt: 3
WIFI : Connected! IP: 192.168.1.36 (ESP_Easy_0)
WD   : Uptime 0 ConnectFailures 0 FreeMem 15488
WS:ac
:rcl
:abort
:ref 1
WS:av
:ref 2
:ur 2
New client
:ref 2
:ur 2
:ur 1
WS:dis
:del
pm open,type:2 0
WD   : Uptime 1 ConnectFailures 0 FreeMem 15376
WD   : Uptime 1 ConnectFailures 0 FreeMem 15376
WD   : Uptime 2 ConnectFailures 0 FreeMem 15376
WD   : Uptime 2 ConnectFailures 0 FreeMem 15376
WD   : Uptime 3 ConnectFailures 0 FreeMem 15376
WD   : Uptime 3 ConnectFailures 0 FreeMem 15376
WD   : Uptime 4 ConnectFailures 0 FreeMem 15376
WD   : Uptime 4 ConnectFailures 0 FreeMem 15376
WD   : Uptime 5 ConnectFailures 0 FreeMem 15376
WD   : Uptime 5 ConnectFailures 0 FreeMem 15376
WD   : Uptime 6 ConnectFailures 0 FreeMem 15376
WS:ac
:rcl
:abort
:ref 1
WS:av
:ref 2
:ur 2
New client
:ref 2
:ur 2
:ur 1
WS:dis
:del
WD   : Uptime 6 ConnectFailures 0 FreeMem 15376
WD   : Uptime 7 ConnectFailures 0 FreeMem 15200
WD   : Uptime 7 ConnectFailures 0 FreeMem 15200
WD   : Uptime 8 ConnectFailures 0 FreeMem 15200
WD   : Uptime 8 ConnectFailures 0 FreeMem 15200
WD   : Uptime 9 ConnectFailures 0 FreeMem 15200
WD   : Uptime 9 ConnectFailures 0 FreeMem 15200
WD   : Uptime 10 ConnectFailures 0 FreeMem 15200
WD   : Uptime 10 ConnectFailures 0 FreeMem 15200

At this point I accessed the ESP via browser. Nothing happend for a few seconds, then it went:


WS:ac
:rn 320
:ref 1
WS:av
:ref 2
:ur 2
New client
:ref 2
:ur 2
method: GET url: / search: 
headerName: Host
headerValue: 192.168.1.36
headerName: User-Agent
headerValue: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:58.0) Gecko/20100101 Firefox/58.0
headerName: Accept
headerValue: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
headerName: Accept-Language
headerValue: en-US,en;q=0.5
headerName: Accept-Encoding
headerValue: gzip, deflate
headerName: Connection
headerValue: keep-alive
headerName: Upgrade-Insecure-Requests
headerValue: 1
:c0 1, 320
args: 
Request: /
 Arguments: 
:ref 2
:ur 2
WS:ac
SPIFFSImpl::open: fd=-10002 path=`TmplStd.htm` openMode=0 accessMode=3 err=-10002
:wr 162 162 0
:wrc 162 162 0
:sent 162
:wr 5 5 0
:wrc 5 5 0
:wr 1067 1913 0
:wrc 256 1067 0
:wrc 256 811 0
:wrc 256 555 0
:wrc 256 299 0
:wrc 43 43 0
:sent 5
:sent 536
:sent 531
:wr 846 846 1067
:wrc 256 846 0
:wrc 256 590 0
:wrc 256 334 0
:wrc 78 78 0
:wr 2 2 0
:wrc 2 2 0
:sent 536
:sent 312
:wr 5 5 0
:wrc 5 5 0
:wr 471 471 0
:wrc 256 471 0
:wrc 215 215 0
:wr 2 2 0
:wrc 2 2 0
:sent 5
:sent 473
:wr 5 5 0
:wrc 5 5 0
:wr 407 407 0
:wrc 256 407 0
:wrc 151 151 0
:wr 2 2 0
:wrc 2 2 0
:sent 5
:sent 409
:wr 4 4 0
:wrc 4 4 0
:wr 72 72 0
:wrc 72 72 0
:wr 2 2 0
:wrc 2 2 0
:sent 4
:sent 74
:wr 3 3 0
:wrc 3 3 0
:wr 2 2 0
:wrc 2 2 0
:sent 3
:sent 2
:rcl
:abort
:ur 1
WS:dis
:del
:ref 1
WS:av
:ref 2
:ur 2
New client
:ref 2
:ur 2
:rcl
:abort
:ur 1
WS:dis
:del
WD   : Uptime 11 ConnectFailures 0 FreeMem 14944
WD   : Uptime 11 ConnectFailures 0 FreeMem 14944
s0170071 commented 6 years ago

It has got something to do with my router and the repeater. If I switch off the repeater, the issue is gone. Still, as this only affects the ESP I'll keep digging.

s0170071 commented 6 years ago

Wireshark capture. Note: the last (red) packet always appears, even if the page loads right away. Is this normal ? Here is the full capture, one for normal operation (with my repeater disabled) the other one with the repeater enabled and the ESP idle time. Wireshark.zip

image

s0170071 commented 6 years ago

About that last packet. I just noticed it has the numbers for ACK and Seq swapped. Looks like a bug to me...

s0170071 commented 6 years ago

Does no one know about Seq and ACK numbers ?

d-a-v commented 6 years ago

@s0170071 There seems to be nothing wrong with seq and ack. What is seq for one peer is at some point acked by the other. On the last two lines, IP are swapped, and so are seq/ack.

Regarding your initial issue, can you check the bottom of #2330 and retry with disabling the power management mode ?

ximon commented 4 years ago

Hi @d-a-v, I'm getting a very similar intermittent issue, some requests come back in <500ms, the odd one will take >5000ms. I'm using PlatformIO and the arduino framework, I have this issue using the arduino IDE. I have a MVP project which replicates this. I've tried disabling the power management mode, makes no difference for me. I've got wireshark logs and debug output with the following specified: DEBUG_ESP_HTTP_SERVER, DEBUG_ESP_CORE, DEBUG_ESP_WIFI

Should i attach them here or create another issue? I added the info here as it sounds very similar to my issue.

Bascht74 commented 3 years ago

@ximon I am using Tasmota and have the same problems as stated from you and @s0170071 . I am using UNIFI AP and Tasmota with Core-Version 2.7.4 / SDK-Version 2.2.2-dev(38a443e)

If I constantly ping the device I usually don't get responses > 2.000 ms

can you please add the MVP or did you created another issue?

Sebastian

s0170071 commented 3 years ago

i am not entirely sure after two years but if you run two routers, in my cases they were FritzBoxes, check if you completed the mesh setup by pressing the wps button on each box as suggested by the UI. Otherwise it will work at first but really strange things happen over time as the two interfere or compete with each other.