The Grinder / Bugs / #189 "HTTPS proxy SSL engine" java.lang.NullPointerException

Philip Aston - 2012-01-10

I think this may be due to concurrent requests coming from the browser.

Could you build from source and add some debug statements to TCPProxySSLSocketFactoryImplementation?

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

tadge - 2012-01-18

Hi Phil. Some debug info below - let me know if I can try anything further.

I have added debug (with currentTimeMillis() and currentThread()):

-- within the TCPProxySSLSocketFactoryImplementation.createClientSocket method (ENTRY/EXIT) logging parameters & return values.

-- within HTTPProxyTCPProxyEngine$HTTPSProxySocketFactory where the value of m_nextRawClientSocket is manipulated (two points in the negotiate method and one in createClientSocket). Also on entry to createClientSocket in this class.

Output is below - what I see happening:

On the main Thread, HTTPSProxySocketFactory.negotiate initialises m_nextRawClientSocket to a Socket addressing my internal proxy server xxxxxx.

On thread "HTTPS proxy SSL engine", HTTPProxyTCPProxyEngine$HTTPSProxySocketFactory.createClientSocket is called. At this point m_nextRawClientSocket is still set.

Then on the main thread, another call to HTTPSProxySocketFactory.negotiate sets m_nextRawClientSocket to null.

On thread "HTTPS proxy SSL engine", TCPProxySSLSocketFactoryImplementation.createClientSocket is called, but at this point the first argument (Socket) is null and we will get an NPE.

The last 3 events all happened with the same timestamp.

NB this is all running on a dual cpu windows pc.

Output:

2012-01-18 18:24:27,827 INFO tcpproxy: Initialising as an HTTP/HTTPS proxy with the parameters:
Request filters: HTTPRequestFilter
Response filters: HTTPResponseFilter
Local address: localhost:8000
HTTP proxy: xxxxxx:8080
HTTPS proxy: xxxxxx:8080
2012-01-18 18:24:28,202 INFO tcpproxy: Engine initialised, listening on port 8000

1326911072905 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null
1326911072921 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=2763]

1326911072921 Thread[HTTPS proxy SSL engine,5,main] DBG: HTTPSProxySocketFactory.createClientSocket entry m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=2763]

1326911072921 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null

1326911072921 Thread[HTTPS proxy SSL engine,5,main] DBG: TCPProxySSLSocketFactoryImplementation.createClientSocket ENTRY null segment-pixel.invitemedia.com:443

1326911072936 Thread[HTTPS proxy SSL engine,5,main] DBG: HTTPSProxySocketFactory.createClientSocket finally m_nextRawClientSocket=null

Exception in thread "HTTPS proxy SSL engine" java.lang.NullPointerException
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.<init>(SSLSocketImpl.java:482)
at com.sun.net.ssl.internal.ssl.SSLSocketFactoryImpl.createSocket(SSLSocketFactoryImpl.java:92)
at net.grinder.tools.tcpproxy.TCPProxySSLSocketFactoryImplementation.createClientSocket(TCPProxySSLSocketFactoryImplementation.java:210)
at net.grinder.tools.tcpproxy.HTTPProxyTCPProxyEngine$HTTPSProxySocketFactory.createClientSocket(HTTPProxyTCPProxyEngine.java:833)
at net.grinder.tools.tcpproxy.AbstractTCPProxyEngine.launchThreadPair(AbstractTCPProxyEngine.java:367)
at net.grinder.tools.tcpproxy.HTTPProxyTCPProxyEngine$ProxySSLEngine.run(HTTPProxyTCPProxyEngine.java:619)
at java.lang.Thread.run(Thread.java:662)
1326911072936 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=2768]
1326911072952 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null
1326911072967 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=2770]</init>

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-23

Thanks. I think that pins it down.

I've created a tentative patch. This is against 3.7 (it will probably work against 3.6 as well). Add the attached jar file to the start of the TCPProxy classpath.

Let me know how you get on.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-23

Candidate patch - add to the start of the TCPProxy classpath.

patch3471476.jar

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

tadge - 2012-01-25

Thanks Phil. I tested it on 3.6 & 3.7 but without success. So I re-instated my debug statements into the build from source plus I added two more inside the edges of your "synchronized (m_proxySSLEngine)" block: "entered/leaving sync" below.

I notice the ordering of the debug lines now seems different than before.

Also HTTPSProxySocketFactory.createClientSocket entry shows m_nextRawClientSocket=null on entry (whereas it was not in the earlier example).

Hope this helps - let me know if I can provide more info. Thanks for looking into it.

C:\projects\grinder\36>java -cp C:\projects\grinder-build\grinder-3.8-SNAPSHOT\lib\grinder.jar net.grinder.TCPProxy -console -http -localport 8000 -httpproxy xxxxxx 8080 1>grinder.py
2012-01-25 17:14:29,323 INFO tcpproxy: Initialising as an HTTP/HTTPS proxy with the parameters:
Request filters: HTTPRequestFilter
Response filters: HTTPResponseFilter
Local address: localhost:8000
HTTP proxy: xxxxxx:8080
HTTPS proxy: xxxxxx:8080
2012-01-25 17:14:29,698 INFO tcpproxy: Engine initialised, listening on port 8000
1327511675370 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run entered sync
1327511675370 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null
1327511675385 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=4494]
1327511675385 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run leaving sync
1327511675385 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run entered sync
1327511675385 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null
1327511675401 Thread[HTTPS proxy SSL engine,5,main] DBG: HTTPSProxySocketFactory.createClientSocket entry m_nextRawClientSocket=null
1327511675401 Thread[HTTPS proxy SSL engine,5,main] DBG: TCPProxySSLSocketFactoryImplementation.createClientSocket ENTRY null segment-pixel.invitemedia.com:443
1327511675401 Thread[HTTPS proxy SSL engine,5,main] DBG: HTTPSProxySocketFactory.createClientSocket finally m_nextRawClientSocket=null
Exception in thread "HTTPS proxy SSL engine" java.lang.NullPointerException
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.<init>(SSLSocketImpl.java:482)
at com.sun.net.ssl.internal.ssl.SSLSocketFactoryImpl.createSocket(SSLSocketFactoryImpl.java:92)
at net.grinder.tools.tcpproxy.TCPProxySSLSocketFactoryImplementation.createClientSocket(TCPProxySSLSocketFactoryImplementation.java:210)
at net.grinder.tools.tcpproxy.HTTPProxyTCPProxyEngine$HTTPSProxySocketFactory.createClientSocket(HTTPProxyTCPProxyEngine.java:841)
at net.grinder.tools.tcpproxy.AbstractTCPProxyEngine.launchThreadPair(AbstractTCPProxyEngine.java:367)
at net.grinder.tools.tcpproxy.HTTPProxyTCPProxyEngine$ProxySSLEngine.run(HTTPProxyTCPProxyEngine.java:626)
at java.lang.Thread.run(Thread.java:662)
1327511675401 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=4502]
1327511675416 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run leaving sync
1327511675416 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run entered sync
1327511675416 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(1) m_nextRawClientSocket=null
1327511675432 Thread[main,5,main] DBG: HTTPSProxySocketFactory.negotiate(2) m_nextRawClientSocket=Socket[addr=xxxxxx/nn.nn.nn.nn,port=8080,localport=4504]
1327511675432 Thread[main,5,main] DBG: HTTPProxyTCPProxyEngine.run leaving sync</init>

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-26

Previous patch was garbage. Working on the right fix...

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-27

Second try - add to the start of the TCPProxy classpath.

patch3471476-2.jar

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-27

Try this patch instead.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

tadge - 2012-01-31

Thanks Phil - that one worked!

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

Philip Aston - 2012-01-31

Thanks Tadge. Fix will be included in the next release.

If you would like to refer to this comment somewhere else in this project, copy and paste the following link:

"HTTPS proxy SSL engine" java.lang.NullPointerException

Distributed load testing framework - Java, Jython, or Clojure scripts.

Group

Searches

Help

#189 "HTTPS proxy SSL engine" java.lang.NullPointerException

Discussion