I'm receiving a javax.net.ssl.SSLException: Received fatal alert: close_notify error on a test server, from my Axis 1.4 generated proxies, running under JBoss AS 4.2.3, JDK 1.6.0_20. The same setup works on my dev machine, albeit with JDK 1.6.0_21. The failure occurs the SECOND time a call is made to the web service.
Here comes the science stack trace:
[19/10/2010 10:20:17][370835685808817|192.168.1.12|MVN|http-0.0.0.0-80-1][DEBUG][MVN][2445] enterprise.invoke - Mapping Exception to AxisFaultAxisFault
faultCode: {http://schemas.xmlsoap.org/soap/envelope/}Server.userException
faultSubcode:
faultString: javax.net.ssl.SSLException: Received fatal alert: close_notify
faultActor:
faultNode:
faultDetail:
{http://xml.apache.org/axis/}stackTrace:javax.net.ssl.SSLException: Received fatal alert: close_notify
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:190)
at com.sun.net.ssl.internal.ssl.Alerts.getSSLException(Alerts.java:136)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.recvAlert(SSLSocketImpl.java:1694)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:939)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1120)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1147)
at com.sun.net.ssl.internal.ssl.SSLSocketImpl.startHandshake(SSLSocketImpl.java:1131)
at org.apache.axis.components.net.JSSESocketFactory.create(JSSESocketFactory.java:186)
at org.apache.axis.transport.http.HTTPSender.getSocket(HTTPSender.java:191)
at org.apache.axis.transport.http.HTTPSender.writeToSocket(HTTPSender.java:404)
at org.apache.axis.transport.http.HTTPSender.invoke(HTTPSender.java:138)
at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
at org.apache.axis.client.AxisClient.invoke(AxisClient.java:165)
at org.apache.axis.client.Call.invokeEngine(Call.java:2784)
at org.apache.axis.client.Call.invoke(Call.java:2767)
at org.apache.axis.client.Call.invoke(Call.java:2443)
at org.apache.axis.client.Call.invoke(Call.java:2366)
at org.apache.axis.client.Call.invoke(Call.java:1812)
at es.aragon.axis1.srt.v2.SRTSoapBindingStub.obtenerOrganismosYTramites(Unknown Source)
at es.aragon.axis1.srt.v2.ProxySRTSoapBindingImpl.obtenerOrganismosYTramites(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.apache.axis.providers.java.RPCProvider.invokeMethod(RPCProvider.java:397)
at org.apache.axis.providers.java.RPCProvider.processMessage(RPCProvider.java:186)
at org.apache.axis.providers.java.JavaProvider.invoke(JavaProvider.java:323)
at org.apache.axis.strategies.InvocationStrategy.visit(InvocationStrategy.java:32)
at org.apache.axis.SimpleChain.doVisiting(SimpleChain.java:118)
at org.apache.axis.SimpleChain.invoke(SimpleChain.java:83)
at org.apache.axis.handlers.soap.SOAPService.invoke(SOAPService.java:454)
at org.apache.axis.server.AxisServer.invoke(AxisServer.java:281)
at org.apache.axis.transport.http.AxisServlet.doPost(AxisServlet.java:699)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:710)
at org.apache.axis.transport.http.AxisServletBase.service(AxisServletBase.java:327)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at es.sitvi.base.filters.Axis1Filter.doFilter(Unknown Source)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at es.sitvi.base.filters.LoggingFilter.doFilter(Unknown Source)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:175)
at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:182)
at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:84)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:157)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:262)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:844)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:446)
at java.lang.Thread.run(Thread.java:619)
{http://xml.apache.org/axis/}hostname:sitvisrv
Attempting to garner more info I've added System.setProperty("javax.net.debug","all"); line before the call. The reduced output is below
2010-10-19 10:20:17,953 INFO [STDOUT]
2010-10-19 10:20:17,953 INFO [STDOUT]
2010-10-19 10:20:17,953 INFO [STDOUT] .
2010-10-19 10:20:17,953 INFO [STDOUT] .
2010-10-19 10:20:17,953 INFO [STDOUT] http-0.0.0.0-80-1, READ: SSLv3 Alert, length = 2
2010-10-19 10:20:17,953 INFO [STDOUT] http-0.0.0.0-80-1
2010-10-19 10:20:17,953 INFO [STDOUT] , RECV SSLv3 ALERT:
2010-10-19 10:20:17,953 INFO [STDOUT] fatal,
2010-10-19 10:20:17,953 INFO [STDOUT] close_notify
2010-10-19 10:20:17,953 INFO [STDOUT] http-0.0.0.0-80-1, called closeSocket()
2010-10-19 10:20:17,953 INFO [STDOUT] http-0.0.0.0-80-1, handling exception: javax.net.ssl.SSLException: Received fatal alert: close_notify
I can see it initializing the keystore, perform various 'Handshake' and 'client hello message' actions, the cert chain is there, see the ClientKeyExchange, etc ... but don't see any differences between the trace of the two servers up to the actual exception.
I've tried recreating importing the certificate into the store anew on the machine but no luck.
Perhaps in Axis I need to select a client certificate for SSL at run time? but why does it work on one server and not the other?!
I shall play some more but any pointers would be appreciated.
Edit: In Apache Axis we can do the following to completely ignore Unsigned SSL Certs:
System.setProperty("axis.socketSecureFactory", "org.apache.axis.components.net.SunFakeTrustSocketFactory");
...And she still blows.
Edit: Well it's 2 vs. 2 here in the office. The error appears on the build and dev servers but not on my machine nor the laptop-that's-seen-so-many-previous-employees-that-I'd-hate-to-see-the-pictures-in-the-browser-cache. Turned off the windows server firewall but still the error appears (would I need to restart the runtime/service, though?).
Edit: Checked the hosts file and applied all entries we have had to add in the project in development to the test server, no change.
Edit: Went to plead for help with our system administrators and confirmed once more that they're as useful as a chocolate fireguard with a hangover. You leave them wanting to punch baby seals in the face out of sheer frustration. However, I did realise from talking to them that the server network configuration will be different to a normal workstation.
Edit: We have two adsl points of entry to the office. One for the servers and the dodgy one for the 'workers' that needs resetting every two hours. Performing a tracert to the end point server is now exactly the same. I'd changed the ip of the DNS on the server to that of my own machine (see ipconfig /all). No change. Next up was the route print command for a looksy at the local IP routing table. Adding the missing routes prove no release. With these changes I've come to the conclusion that I am both a risk to society and the system administrators who look after the servers.
I've spent the last 4 days oscillating between trying to solve the problem or sitting on the toilet taking increasing quantities of crack. I am not really getting any further on this one, time to give it all up and start gardening.