BUG: Is the serial port blocking the webserver?

Moderators: grovkillen, TD-er, Stuntteam

Post Reply
Message
Author
User avatar
moelski
Normal user
Posts: 124
Joined: 31 Aug 2016, 06:33
Location: Germany - NRW
Contact:

BUG: Is the serial port blocking the webserver?

#1 Post by moelski » 21 Oct 2016, 11:47

Hi @all,

today I installed a SOnOff with ESPEasy R136. It´s just a plain R136 compilation with the switch input and 2 system information tasks.
I included the SonOff to my FHEM setup and just call http://192.168.xxx.xxx/control?cmd=GPIO,12,0|1 to switch the relais on or off.
This works - mostly.

After some time I figured out that the response was very slow - sometimes more than 9 seconds :o

So I run Fiddler to check the request / response time. See the first picture where everthing is ok. The response time is around 30-40 milliseconds.
At the second picture the serial port is enabled in the advanced settings. And from time to time the communication hangs :o

There are response times from over 9 seconds. And that results in a timeout :cry:

So can anyone of the devs check if there is something blocking on the serial part? I should mention that the serial port is not connected to a computer during this test.
But I have never had such a problem before.
Attachments
Response is OK
Response is OK
WebServerResponse01.PNG (48.16 KiB) Viewed 1543 times
Response is BAD
Response is BAD
WebServerResponse02.PNG (38.31 KiB) Viewed 1543 times
regards
Dominik

Martinus

Re: BUG: Is the serial port blocking the webserver?

#2 Post by Martinus » 21 Oct 2016, 16:49

I'm using this little VB script to verify webrequests:

Code: Select all

ip = WScript.Arguments.Item(0)

Set objFSO = CreateObject("Scripting.FileSystemObject")
Set objLogFile = objFSO.createTextFile("webtestlog_" & ip & ".txt", True)

count=0                  ' count number of requests
errors=0                 ' count request with returncode <> 200
min=10000                ' keep track of fastest response
max=0                    ' keep track of slowest response
onesecond=0              ' count number of requests beyond one second response time
total=0                  ' count total time
state=1                  ' track gpio toggle state

do while true
  if state =1 then
    state = 0
  else
    state = 1
  end if
  Set objHTTP = CreateObject( "WinHttp.WinHttpRequest.5.1" )
  objHTTP.Open "GET", "http://" & ip & "/control?cmd=gpio,2," & state, False
  objHTTP.SetRequestHeader "User-Agent", "Mozilla/4.0 (compatible; MyApp 1.0; Windows NT 5.1)"

  on error resume next
  start = timer()
  objHTTP.Send
  duration = (timer()-start) * 1000
  intStatus = objHTTP.Status
  Set objHTTP = Nothing
  on error goto 0
  
  if intStatus = 200 then
    count = count + 1
    total = total + duration
    if duration > 1000 then
      onesecond = onesecond + 1
    end if
    if duration > max then
      max = duration
    end if
    if duration < min then
      min = duration
    end if
    logging = "Cnt:" & count & "  Dur:" & round(duration) & "mS  Min:" & round(min) & "mS  Max:" & round(max) & "mS  Avg:" & round(total/count) & "mS  >1s:" & round(onesecond) & "  Err:" & round(errors)
  else
    errors = errors + 1
    logging = "Errors: " & errors
  end if
  Wscript.echo logging
  objLogFile.writeline(logging)
  Wscript.sleep 1000
loop
It toggles GPIO2 on and off using http requests. I let it run for about 10 minutes on my Sonoff device with serial and weblogging both set to level 2. Last part of the logfile:

Code: Select all

Cnt:606  Dur:94mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:607  Dur:98mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:608  Dur:98mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:609  Dur:90mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:610  Dur:82mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:611  Dur:86mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:612  Dur:78mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:613  Dur:74mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:614  Dur:102mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:615  Dur:94mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:616  Dur:82mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:617  Dur:86mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:618  Dur:148mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:619  Dur:82mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:620  Dur:74mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
Cnt:621  Dur:94mS  Min:62mS  Max:2098mS  Avg:93mS  >1s:4  Err:0
More than 600 requests fired, one request per second, no errors, average response 93 milliSeconds and maximum 2098 mSeconds.
4 requests took longer than 1 second.
Sonoff runs R140

User avatar
moelski
Normal user
Posts: 124
Joined: 31 Aug 2016, 06:33
Location: Germany - NRW
Contact:

Re: BUG: Is the serial port blocking the webserver?

#3 Post by moelski » 22 Oct 2016, 07:50

Hi Martinus,

this is strange 8-)
I will try the latest Github version today and test if it works better ...
regards
Dominik

User avatar
moelski
Normal user
Posts: 124
Joined: 31 Aug 2016, 06:33
Location: Germany - NRW
Contact:

Re: BUG: Is the serial port blocking the webserver?

#4 Post by moelski » 23 Oct 2016, 19:25

Hi Martinus,

I flashed the 141 today and at first it looks ok. But ofter some tests it seems that the problem still exists.
This is what I did:
* Compile & Flash R141
* Enable Web and Serial Logging
* Set Loglevel serial to 2 (Default)
At this stage everthing seems to be ok.

But after setting the serial Loglevel to 4 there are sometimes delays if you toggle the Output relais of the SonOff very fast.

It seems a little bit better than the test with R136. But anyway ... Looks like to serial Output generates some delay.

I wasn´t able to reproduce these really long delays from ~9 seconds like in my initial posting.
But maybe you can give it a try with loglevel 4 on serial Log.
regards
Dominik

Post Reply

Who is online

Users browsing this forum: Google [Bot] and 5 guests