Skip to content
This repository has been archived by the owner on Nov 29, 2018. It is now read-only.

Selenium's proxy server performance regression for HTTPS pages #3498

Closed
lukeis opened this issue Mar 3, 2016 · 13 comments
Closed

Selenium's proxy server performance regression for HTTPS pages #3498

lukeis opened this issue Mar 3, 2016 · 13 comments

Comments

@lukeis
Copy link
Member

lukeis commented Mar 3, 2016

Originally reported on Google Code with ID 3498

Since release 2.20.0, Selenium's proxy server's performance has gone down considerably
on HTTPS pages for a reason I still don't fully understand.

Here's a simple comparison (durations outlined in Sauce's log, but noticeable while
watching the videos).
Notice: this is reflected in Sauce as we proxy all of our browsers' traffic through
the Selenium proxy.

Se 2.18.0 (9 seconds to load the page): https://saucelabs.com/jobs/38c602db9ddf54a031f1b8c5fb67747b
Se 2.19.0 (9 seconds to load the page): https://saucelabs.com/jobs/38c602db9ddf54a031f1b8c5fb67d7ad
Se 2.20.0 (156 seconds to load the page): https://saucelabs.com/jobs/38c602db9ddf54a031f1b8c5fb67873b

Tested in both Mac and Windows. 

sso➜~/bin/sel-servers» java -version
java version "1.6.0_29"
Java(TM) SE Runtime Environment (build 1.6.0_29-b11-402-10M3527)
Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02-402, mixed mode)

Here's a gist to repro case for Se2 on Java. Make sure the Se jar is running on port
4444 before starting this script:
https://gist.github.com/1981343

Reported by santiycr on 2012-03-05 21:52:16

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

This only seems to happen for the first connection. Rerunning your example test twice
without restarting the browser leads to significantly faster download times.

Looking at the output from the proxy server, it looks like it's binding the ssl sockets
lazily, and this is what's taking the time.

Reported by simon.m.stewart on 2012-03-31 10:40:40

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

We are having the same problem, SSL pages run slowly on first page load.

Command we used:

"C:\Program Files (x86)\Java\jre6\bin\java.exe" -jar "C:\Selenium\selenium-server-2.20.0\selenium-server-standalone-2.20.0.jar"
-port 5775 -trustAllSSLCertificates -debug

Here's a debug log from the selenium-server-standalone jar:

20:25:13.766 INFO - Command request: open[https://www.google.com, ] on session 50f3bb70ddaa405fbbb19497008598c5
20:25:13.766 DEBUG - Executing 'open' selenium core command on session 50f3bb70ddaa405fbbb19497008598c5
20:25:13.769 DEBUG - Session 50f3bb70ddaa405fbbb19497008598c5 going to doCommand(open,https://www.google.com,)
20:25:13.769 DEBUG - ---------retrieving CommandQueue for sel_67043
20:25:13.769 DEBUG -    sel_67043 commandHolder sel_67043 getCommand()
20:25:13.769 DEBUG - putting command: json={command:"open",target:"https://www.google.com",value:""}
20:25:13.769 DEBUG - ..command put?: true
20:25:13.769 DEBUG - data from polling: json={command:"open",target:"https://www.google.com",value:""}
20:25:13.769 DEBUG -    sel_67043 commandResultHolder sel_67043 getResult() called
20:25:13.769 DEBUG -    sel_67043 commandHolder sel_67043 getCommand() -> json={command:"open",target:"https://www.google.com",value:""}
20:25:13.769 DEBUG - waiting for data for at most 1800 more s
20:25:13.770 DEBUG - res to sel_67043: json={command:"open",target:"https://www.google.com",value:""}
20:25:13.773 DEBUG - CONNECT: www.google.com:443
20:25:13.778 DEBUG - Extracting /sslSupport to C:\Users\UserNameHere\AppData\Local\Temp\seleniumSslSupport4901050865690951800www.google.com
20:25:14.215 DEBUG - CONNECT: sb-ssl.google.com:443
6228 [SocketListener0-10] INFO org.openqa.jetty.http.SocketListener - Started SocketListener
on 0.0.0.0:6369
20:25:15.056 DEBUG - Extracting /sslSupport to C:\Users\UserNameHere\AppData\Local\Temp\seleniumSslSupport8651721234162468525sb-ssl.google.com
6859 [SocketListener0-11] INFO org.openqa.jetty.http.SocketListener - Started SocketListener
on 0.0.0.0:6372

<--------- delay -------->

20:26:05.330 DEBUG - CONNECT: www.google.com:443
20:26:05.336 DEBUG - CONNECT: sb-ssl.google.com:443
20:26:05.367 DEBUG - PROXY URL=https://sb-ssl.google.com:443/safebrowsing/newkey?client=navclient-auto-ffox&appver=11.0&pver=2.2
20:26:05.430 DEBUG - PROXY URL=https://www.google.com:443/
20:26:05.469 DEBUG - Content-Type is: application/vnd.google.safebrowsing-key
20:26:05.591 DEBUG - Content-Type is: text/html; charset=UTF-8

Reported by michael.henning.ferrante on 2012-04-03 03:35:22

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

This issue was closed by revision r16442.

Reported by simon.m.stewart on 2012-04-03 21:42:30

  • Status changed: Fixed

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Changes so far did make a speed up when "-trustAllSSLCertificates" is not set.

However, as of revision 16503 on the http://selenium.googlecode.com/svn/trunk there
is still and issue of slowness when "-trustAllSSLCertificates" is set. If we don't
use "-trustAllSSLCertificates" it is fast and doesn't have the EOFException() errors.

Attached are files showing the debug console output without trustAllSSLCertificates
(fast) and with trustAllSSLCertificates (slow).

Command Line:
   java.exe -jar "C:\svn\sitkatech\trunk\Libraries\SeleniumBrowserAutomationFramework\selenium-server-2.20.0\selenium-server-standalone-2.20.0-trunk.jar"
-trustAllSSLCertificates -port 5775 -debug

DotNet commands:

   var browser = new DefaultSelenium("localhost", ServerPort, @"*firefox c:\Program
Files (x86)\Mozilla Firefox\firefox.exe", "https://www.google.com");
   browser.Start();
   browser.SetTimeout("180000");
   browser.Open("https://www.wellsfargo.com/favicon.ico");
   browser.Open("https://www.google.com/favicon.ico");

Selenium Commands:
   getTitle()
   setContext(ef8791c96a1a467cb556219499c572e2)
   setTimeout(180000)
   open(https://www.wellsfargo.com/favicon.ico)
   open(https://www.google.com/favicon.ico)

Console Log from selenium-server-standalone.jar:

1:07:25.768 DEBUG - new HttpConnection: a0864f[SSL_NULL_WITH_NULL_NULL: Socket[addr=/127.0.0.1,port=20206,localport=20205]]
21:07:25.766 DEBUG - Extracting /sslSupport to C:\Users\michael\AppData\Local\Temp\seleniumSslSupport418289478598634324sb-ssl.google.com
21:07:25.768 DEBUG - Tunnel: org.openqa.jetty.http.HttpTunnel@d1e233
21:07:26.080 DEBUG - add component: ProxyHandler$SslRelay2@0.0.0.0:0
21:07:26.087 INFO - Started SocketListener on 0.0.0.0:20207
21:07:26.087 DEBUG - Handled by org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:07:26.088 DEBUG - new HttpConnection: 22d166[SSL_NULL_WITH_NULL_NULL: Socket[addr=/127.0.0.1,port=20208,localport=20207]]
21:07:26.088 DEBUG - RESPONSE:
HTTP/1.1 200 OK
Date: Tue, 10 Apr 2012 04:07:24 GMT
Server: Jetty/5.1.x (Windows 7/6.1 x86 java/1.6.0_30
Connection: close
Content-Length: 0


21:07:26.090 DEBUG - Tunnel: org.openqa.jetty.http.HttpTunnel@1e1962d
21:07:27.989 DEBUG - EOFException()
21:07:32.989 DEBUG - EOFException()


<--------- delay -------->


21:08:02.746 DEBUG - new HttpConnection: Socket[addr=/0:0:0:0:0:0:0:1,port=20209,localport=5775]
21:08:02.747 DEBUG - REQUEST from SocketListener0@0.0.0.0:5775:
CONNECT sb-ssl.google.com:443 HTTP/1.1
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:11.0) Gecko/20100101 Firefox/11.0
Proxy-Connection: keep-alive
Host: sb-ssl.google.com


21:08:02.749 DEBUG - Try HttpContext[/,/],0
21:08:02.750 DEBUG - RestishHandler org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.750 DEBUG - CONNECT: sb-ssl.google.com:443
21:08:02.751 DEBUG - Handled by org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.752 DEBUG - new HttpConnection: 1250ff2[SSL_NULL_WITH_NULL_NULL: Socket[addr=/127.0.0.1,port=20210,localport=20207]]
21:08:02.752 DEBUG - RESPONSE:
HTTP/1.1 200 OK
Date: Tue, 10 Apr 2012 04:08:02 GMT
Server: Jetty/5.1.x (Windows 7/6.1 x86 java/1.6.0_30
Connection: close
Content-Length: 0


21:08:02.755 DEBUG - Tunnel: org.openqa.jetty.http.HttpTunnel@864e43
21:08:02.754 DEBUG - new HttpConnection: Socket[addr=/0:0:0:0:0:0:0:1,port=20211,localport=5775]
21:08:02.756 DEBUG - REQUEST from SocketListener0@0.0.0.0:5775:
CONNECT www.wellsfargo.com:443 HTTP/1.1
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:11.0) Gecko/20100101 Firefox/11.0
Proxy-Connection: keep-alive
Host: www.wellsfargo.com


21:08:02.757 DEBUG - Try HttpContext[/,/],0
21:08:02.758 DEBUG - RestishHandler org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.758 DEBUG - CONNECT: www.wellsfargo.com:443
21:08:02.759 DEBUG - Handled by org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.759 DEBUG - RESPONSE:
HTTP/1.1 200 OK
Date: Tue, 10 Apr 2012 04:08:02 GMT
Server: Jetty/5.1.x (Windows 7/6.1 x86 java/1.6.0_30
Connection: close
Content-Length: 0


21:08:02.761 DEBUG - Tunnel: org.openqa.jetty.http.HttpTunnel@6f8b2b
21:08:02.762 DEBUG - new HttpConnection: 182c132[SSL_NULL_WITH_NULL_NULL: Socket[addr=/127.0.0.1,port=20212,localport=20205]]
21:08:02.765 DEBUG - java.net.SocketException: Software caused connection abort: recv
failed
21:08:02.786 DEBUG - REQUEST from ProxyHandler$SslRelay2@0.0.0.0:20207:
GET https://sb-ssl.google.com:443/safebrowsing/newkey?client=navclient-auto-ffox&appver=11.0&pver=2.2
HTTP/1.1
Host: sb-ssl.google.com
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:11.0) Gecko/20100101 Firefox/11.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Connection: keep-alive


21:08:02.789 DEBUG - Try HttpContext[/,/],0
21:08:02.790 DEBUG - RestishHandler org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.790 DEBUG - REQUEST from ProxyHandler$SslRelay1@0.0.0.0:20205:
GET https://www.wellsfargo.com:443/favicon.ico HTTP/1.1
Host: www.wellsfargo.com
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:11.0) Gecko/20100101 Firefox/11.0
Accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
Accept-Language: en-us,en;q=0.5
Accept-Encoding: gzip, deflate
Connection: keep-alive
Referer: http://localhost:5775/selenium-server/core/Blank.html


21:08:02.790 DEBUG - PROXY URL=https://sb-ssl.google.com:443/safebrowsing/newkey?client=navclient-auto-ffox&appver=11.0&pver=2.2
21:08:02.793 DEBUG - Try HttpContext[/,/],0
21:08:02.794 DEBUG - RestishHandler org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.794 DEBUG - PROXY URL=https://www.wellsfargo.com:443/favicon.ico
21:08:02.896 DEBUG - Content-Type is: application/vnd.google.safebrowsing-key
21:08:02.897 DEBUG - Handled by org.openqa.selenium.server.ProxyHandler in HttpContext[/,/]
21:08:02.897 DEBUG - RESPONSE:
HTTP/1.1 200 OK
Date: Tue, 10 Apr 2012 04:08:02 GMT
Server: Chunked Update Server
Content-Type: application/vnd.google.safebrowsing-key
Set-Cookie: PREF=ID=96e4056a708ab55f:TM=1334030882:LM=1334030882:S=oJH0NZPOAdZ-ePFd;
expires=Thu, 10-Apr-2014 04:08:02 GMT; path=/; domain=.google.com
X-Content-Type-Options: nosniff
Content-Length: 154
X-XSS-Protection: 1; mode=block
X-Frame-Options: SAMEORIGIN
Expires: Tue, 10 Apr 2012 04:08:02 GMT
Cache-Control: private
Via: 1.1 (jetty)

Reported by michael.henning.ferrante on 2012-04-10 04:21:24


- _Attachment: [FullTraceSlow.txt](https://storage.googleapis.com/google-code-attachments/selenium/issue-3498/comment-5/FullTraceSlow.txt)_ - _Attachment: [FullTraceFast.txt](https://storage.googleapis.com/google-code-attachments/selenium/issue-3498/comment-5/FullTraceFast.txt)_

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Just confirmed with the Sauce cloud as Michael did, this issue seems to still be present
for windows machines.

Reported by santiycr on 2012-04-12 06:31:10

  • Status changed: Accepted

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

I am still having this issue also using -trustAllSSLCertificates, Linux, tried both
openjdk 1.6 and 1.7. 

Reported by jeffrey.m.weiss on 2012-05-31 21:49:21

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Any ETA on fixing this?

Reported by vasikarla.raj on 2012-08-16 21:04:49

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

I've been working on this issue for the last few weeks with the help of David Hook,
from the bouncycastle dev team. We're close to a resolution.

Reported by santiycr on 2012-12-17 04:34:08

  • Status changed: Started

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Solved in r18355. Please test and report back!

Reported by santiycr on 2012-12-17 04:50:45

  • Status changed: Fixed

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

You can use the following jar in case you don't know how to build from trunk:
https://dl.dropbox.com/u/129692/selenium-standalone.jar

Reported by santiycr on 2012-12-17 04:51:33

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Re-opening and reverting r18355 until the final release of Bouncycastle including the
new required API comes out.

Reported by santiycr on 2012-12-17 17:57:21

  • Status changed: Started

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Fixed in 5f7d034c216e3d36cc11fe67daddbb7ea1ba0baf

Reported by santiycr on 2013-02-13 22:28:45

  • Status changed: Fixed

@lukeis
Copy link
Member Author

lukeis commented Mar 3, 2016

Reported by luke.semerau on 2015-09-17 18:14:55

  • Labels added: Restrict-AddIssueComment-Commit

@lukeis lukeis closed this as completed Mar 3, 2016
@SeleniumHQ SeleniumHQ locked and limited conversation to collaborators Mar 4, 2016
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

1 participant