Issue Details (XML | Word | Printable)

Key: GLASSFISH-15653
Type: Bug Bug
Status: Closed Closed
Resolution: Fixed
Priority: Critical Critical
Assignee: Tim Quinn
Reporter: sonialiu
Votes: 0
Watchers: 1
Operations

If you were logged in you would be able to see more operations.
glassfish

[REGRESSION] 40+ ssl and wss test cases failed in b38

Created: 21/Jan/11 01:27 PM   Updated: 18/Feb/11 12:05 PM   Resolved: 25/Jan/11 04:30 PM
Component/s: security
Affects Version/s: 3.1_b38
Fix Version/s: 3.1_b39

Time Tracking:
Not Specified

Environment:

solaris10


Tags: 3_1-approved 3_1-regression 3_1-verified
Participants: Chris Kasso, kumarjayanti, Nithya Ramakrishnan, sonialiu and Tim Quinn


 Description  « Hide

More than 40+ ssl, wss related test cases failed in b38, this is a regression bug since all these tests passed in b37. The list of failed test cases:
appserver-sqe/pe/security/ssl/clientcert
appserver-sqe/pe/security/ssl/interop
appserver-sqe/pe/security/ssl/clientcertnickname
appserver-sqe/pe/security/ssl/converter
appserver-sqe/pe/security/wss/runasubject/servletws
appserver-sqe/pe/security/wss/dynencryptkey/servletws
appserver-sqe/pe/security/wss/enforcepolicy/servletws
appserver-sqe/pe/security/wss/ejbws
appserver-sqe/pe/security/wss/mesgmethod/servletws
appserver-sqe/pe/security/wss/mesgoperation/ejbws
appserver-sqe/pe/security/wss/mesgoperation/usrpwd/ejbws
appserver-sqe/pe/security/wss/encrypt/ejbws
appserver-sqe/pe/security/wss/userpassword/ejbws/.
appserver-sqe/pe/security/wss/clienthandler/ejbws
appserver-sqe/pe/security/wss/clientmesgoperation/ejbws
appserver-sqe/pe/security/wss/clientmesgoperation/servletws
appserver-sqe/pe/security/wss/sslwss/transpo/ejbws
appserver-sqe/pe/security/wss/sslwss/clientcerto/ejbws/

Steps to reproduce the bug:
1.Checkout SQE workspace:
cvs co appserver-sqe/bootstrap.xml
(CVSROOT=:pserver:cvsguest@sunsw.sfbay.sun.com:/m/jws)
cd appserver-sqe
ant -f bootstrap.xml co-security
2. install GF V3.1, start domain domain1
3. Setup env. variables
S1AS_HOME <GF installation dir> (example: /export/sonia/v3/glassfishv3/glassfish
SPS_HOME <workspace dir> (example: /export/sonia/appserver-sqe)
ANT_HOME <ant dir>
JAVA_HOME <java dir> (I use jdk1.6.0_23)
4. cd appserver-sqe/, run "ant startDerby" to start derby
5. cd appserver-sqe/pe/security/ssl, run "ant setup"
6. cd appserver-sqe/pe/security/ssl/clientcert, run "ant all"
The test failed and the following exception displayed at client:

[exec] main, handling exception: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] main, called close()
[exec] main, called closeInternal(true)
[exec] Got Exception!!! All tests marked as failed!
[exec] java.rmi.MarshalException: CORBA COMM_FAILURE 1330446339 Maybe; nested exception is:
[exec] org.omg.CORBA.COMM_FAILURE: FINE: IOP00410003: Write error sent vmcid: OMG minor code: 3 completed: Maybe
[exec] at com.sun.corba.ee.impl.javax.rmi.CORBA.Util.mapSystemException(Util.java:259)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:213)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
[exec] at com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
[exec] at com.sun.s1peqe.security.realmperapp._SecAuthTestRemoteHome_DynamicStub.create(com/sun/s1peqe/security/realmperapp/_SecAuthTestRemoteHome_DynamicStub.java)
[exec] at com.sun.s1peqe.security.realmperapp.RealmPerAppTestClient.doTests(RealmPerAppTestClient.java:63)
[exec] at com.sun.s1peqe.security.realmperapp.RealmPerAppTestClient.main(RealmPerAppTestClient.java:37)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[exec] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[exec] at java.lang.reflect.Method.invoke(Method.java:597)
[exec] at org.glassfish.appclient.client.acc.AppClientContainer.launch(AppClientContainer.java:432)
[exec] at org.glassfish.appclient.client.AppClientFacade.launch(AppClientFacade.java:182)
[exec] at org.glassfish.appclient.client.AppClientGroupFacade.main(AppClientGroupFacade.java:65)
[exec] Caused by: org.omg.CORBA.COMM_FAILURE: FINE: IOP00410003: Write error sent vmcid: OMG minor code: 3 completed: Maybe
[exec] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[exec] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
[exec] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
[exec] at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
[exec] at com.sun.corba.ee.spi.orbutil.logex.corba.CorbaExtension.makeException(CorbaExtension.java:248)
[exec] at com.sun.corba.ee.spi.orbutil.logex.corba.CorbaExtension.makeException(CorbaExtension.java:95)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator.handleFullLogging(WrapperGenerator.java:387)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator.access$400(WrapperGenerator.java:107)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator$2.invoke(WrapperGenerator.java:511)
[exec] at com.sun.corba.ee.spi.orbutil.proxy.CompositeInvocationHandlerImpl.invoke(CompositeInvocationHandlerImpl.java:99)
[exec] at $Proxy34.writeErrorSend(Unknown Source)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.sendWithoutLock(SocketOrChannelConnectionImpl.java:999)
[exec] at com.sun.corba.ee.impl.encoding.BufferManagerWriteStream.sendFragment(BufferManagerWriteStream.java:151)
[exec] at com.sun.corba.ee.impl.encoding.BufferManagerWriteStream.sendMessage(BufferManagerWriteStream.java:165)
[exec] at com.sun.corba.ee.impl.encoding.CDROutputObject.finishSendingMessage(CDROutputObject.java:200)
[exec] at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.finishSendingRequest(CorbaMessageMediatorImpl.java:274)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete1(CorbaClientRequestDispatcherImpl.java:401)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete(CorbaClientRequestDispatcherImpl.java:368)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.invoke(CorbaClientDelegateImpl.java:264)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:200)
[exec] ... 12 more
[exec] Caused by: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(RSAClientKeyExchange.java:97)
[exec] at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverHelloDone(ClientHandshaker.java:744)
[exec] at com.sun.net.ssl.internal.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:238)
[exec] at com.sun.net.ssl.internal.ssl.Handshaker.processLoop(Handshaker.java:593)
[exec] at com.sun.net.ssl.internal.ssl.Handshaker.process_record(Handshaker.java:529)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:893)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
[exec] at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.readFully(SocketOrChannelConnectionImpl.java:604)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.read(SocketOrChannelConnectionImpl.java:439)
[exec] at com.sun.corba.ee.impl.protocol.giopmsgheaders.MessageBase.readGIOPHeader(MessageBase.java:139)
[exec] at com.sun.corba.ee.impl.protocol.giopmsgheaders.MessageBase.readGIOPMessage(MessageBase.java:127)
[exec] at com.sun.corba.ee.impl.transport.CorbaContactInfoBase.createMessageMediator(CorbaContactInfoBase.java:147)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.readBits(SocketOrChannelConnectionImpl.java:362)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.read(SocketOrChannelConnectionImpl.java:339)
[exec] at com.sun.corba.ee.impl.transport.ReaderThreadImpl.doWork(ReaderThreadImpl.java:112)
[exec] at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:497)
[exec] at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:540)
[exec] Caused by: java.security.NoSuchAlgorithmException: SunTlsRsaPremasterSecret KeyGenerator not available
[exec] at javax.crypto.KeyGenerator.<init>(DashoA13*..)
[exec] at javax.crypto.KeyGenerator.getInstance(DashoA13*..)
[exec] at com.sun.net.ssl.internal.ssl.JsseJce.getKeyGenerator(JsseJce.java:223)
[exec] at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(RSAClientKeyExchange.java:89)
[exec] ... 18 more
[exec] Generating report at /export/sonia/appserver-sqe/test_results.xml
[exec]
[exec]
[exec] -----------------------------------------
[exec] - CertificateRealmPerApp-AppLevel-Test2.testIsCallerIsExcepted(): FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test1.testIsCallerIsInRole(): FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test4.Calling-Not-authorized-method: FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test3.Calling-authorized-method: FAIL -
[exec] -----------------------------------------
[exec] Total PASS: 0
[exec] Total FAIL: 4
[exec] Total DNR: 0

----------
There is no exceptions in server.log
-----------------------
The exceptions for wss tests are different, but also related to the SSL. I did not report a separate bug. Please take a look at the exceptions below and let me know if I need to report a separate bug.
Steps to reproduce the wss/sslwss failures:
1. cd appserver-sqe/pe/security/ssl, run "ant setup enable-wss-log"
2. cd appserver-sqe/pe/security/ssl/sslwss, run "ant all". The test failed and the following errors displayed:

[exec] java.rmi.RemoteException: HTTP transport error: javax.net.ssl.SSLKeyException: RSA premaster secret error; nested exception is:
[exec] HTTP transport error: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] at com.sun.appserv.sqe.security.wss.ejbws.taxcal.client.FedTaxIF_Stub.getFedTax(FedTaxIF_Stub.java:88)
[exec] at com.sun.appserv.sqe.security.wss.ejbws.taxcal.client.TaxCalClient.callFedTaxService(TaxCalClient.java:89)
[exec] at com.sun.appserv.sqe.security.wss.ejbws.taxcal.client.TaxCalClient.main(TaxCalClient.java:43)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[exec] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[exec] at java.lang.reflect.Method.invoke(Method.java:597)
[exec] at org.glassfish.appclient.client.acc.AppClientContainer.launch(AppClientContainer.java:432)
[exec] at org.glassfish.appclient.client.AppClientFacade.launch(AppClientFacade.java:182)
[exec] at org.glassfish.appclient.client.AppClientGroupFacade.main(AppClientGroupFacade.java:65)
[exec] Caused by: HTTP transport error: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] at com.sun.xml.rpc.client.http.HttpClientTransport.invoke(HttpClientTransport.java:165)
[exec] at com.sun.xml.rpc.client.StreamingSender._send(StreamingSender.java:113)
[exec] at com.sun.appserv.sqe.security.wss.ejbws.taxcal.client.FedTaxIF_Stub.getFedTax(FedTaxIF_Stub.java:71)
[exec] ... 9 more
[exec] ]
[exec] *** ServerHelloDone
[exec] main, handling exception: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] main, SEND TLSv1 ALERT: fatal, description = unexpected_message
[exec] main, WRITE: TLSv1 Alert, length = 2
[exec] main, called closeSocket()
[exec] main, called close()
[exec] main, called closeInternal(true)
[exec] TaxCalEjbWebService client failed
[exec] Generating report at /export/sonia/appserver-sqe/test_results.xml
[exec]
[exec]
[exec] -----------------------------------------
[exec] - Security-WSS-SSL-Transport-user-password-TaxCalEjbbasedWS-StateTaxPort: FAIL -
[exec] - Security-WSS-SSL-Transport-user-password-TaxCalEjbbasedWS-FedTaxPort: FAIL -
[exec] -----------------------------------------
[exec] Total PASS: 0
[exec] Total FAIL: 2
[exec] Total DNR: 0
[exec] -----------------------------------------



kumarjayanti added a comment - 23/Jan/11 03:33 AM

I used the very latest builds and i cannot reproduce the failure. The only difference though is that i am using 1.6.0_22 on my MAC.

[exec] Got expected AccessException!
[exec] Generating report at /Users/vbkumarjayanti/Documents/workspace/SQE/appserver-sqe/test_results.xml
[exec]
[exec]
[exec] -----------------------------------------
[exec] - CertificateRealmPerApp-AppLevel-Test2.testIsCallerExcepted(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test1..testIsCallerIsInRole(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test4.Calling-Not-authorized-method: PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test3.Calling-authorized-method: PASS -
[exec] -----------------------------------------
[exec] Total PASS: 4
[exec] Total FAIL: 0
[exec] Total DNR: 0
[exec] -----------------------------------------


kumarjayanti added a comment - 23/Jan/11 03:47 AM

I thing you may want to check is make sure is whether the security classes normally contained in the path given by the default System property java.ext.dirs are present. Check whether jre/lib/ext/sunpkcs11.jar and sunjce_provider.jar exist in the java.ext.dirs path.

domain.xml :

<jvm-options>-Djava.ext.dirs=${com.sun.aas.javaRoot}/lib/ext${path.separator}${com.sun.aas.javaRoot}/jre/lib/ext${path.separator}${com.sun.aas.instanceRoot}/lib/ext</jvm-options>

Missing jars from java.ext.dirs is the primary reason for RSA PreMaster Secret error.

So i suspect your JDK 1.6.0_23 install is incomplete/faulty ?, Or java.ext.dirs did not expand correctly ?.


sonialiu added a comment - 24/Jan/11 10:47 AM

We could reproduce the issue on all of the SQE hudson machines(linux/solaris/window) and my local machine(solaris 10) against b38. I also tried the latest nightly build (01/24) on my local machine, these tests failed with the same error. The jdk versions are jdk1.6.0_22, 1.6,0_23. So, I think the issue is real and could you please look into it once more? Thanks.


kumarjayanti added a comment - 24/Jan/11 08:02 PM - edited

I tried again but am unable to reproduce all the tests pass on my system, including the WebServices SSL tests.

Two things :

1. Do i need to update my SQE workspace, it is about 2 months old. Have you made some changes to SQE setup/scripts which is causing this failure ?

2. When i test, i use he latest workspace built locally on my system and install using glassfish.zip. I believe you use the installer right ?. So point me to the place from where you are downloading the bits and reopen the bug.

Also give us VNC access to one failing setup and instructions to reproduce on the setup.


sonialiu added a comment - 24/Jan/11 09:05 PM

Thanks for looking at the issue.
1. Since the tests passed on b37, I guess the regression happened between b37 to b38, I did not change the SQE test code recently.
2. I got the installer bits from /net/koori.sfbay.sun.com/onestop/glassfish/v3.1/promoted/b38/archives/bundles/glassfish-3.1-b38.zip (the hudson jobs get the build from http://download.java.net/glassfish/3.1/promoted/latest-glassfish.zip). I just do unzip glassfish-3.1-b38.zip to install the bits, then cd glassfish3/glassfish/bin, run "asadmin start-domain domain1" to start domain
3. Please check my local solaris machine to reproduce the bug:
rlogin jed-asqe-2.us.oracle.com -l aroot (I will send you password in a separate email)
tcsh
source /export/sonia/.cshrc
The GF is installed at /export/sonia/v3/glassfish3 (it's the 01/24 nightly build)
cd appserver-sqe/pe/security/ssl, run "ant setup" (I have done this on the machine)
cd appserver-sqe/pe/security/ssl/clientcert, run "ant all" (I have run it once this morning and the execution log all.log.0124 is saved at this dir)


kumarjayanti added a comment - 24/Jan/11 09:21 PM

If possible can you try using the zip from here and try on a fresh setup.

http://gf-hudson.us.oracle.com/hudson/view/GFv3%20Trunk/job/gf-trunk-build-continuous/

meantime i will try to login to your system and see what is wrong. And i will also try with the build you are suggesting.


kumarjayanti added a comment - 24/Jan/11 09:34 PM

retested with latest workspace build : at SVN revision 44692

[exec] Test1..Calling testIsCallerInRole()...
[exec] main, WRITE: TLSv1 Application Data, length = 324
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 57
[exec] Test2.Calling testIsCallerExpected()...
[exec] main, WRITE: TLSv1 Application Data, length = 524
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 57
[exec] Test3.Calling authorized method - methodIsAuthorized():
[exec] main, WRITE: TLSv1 Application Data, length = 238
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 57
[exec] Test4.Calling unauthorized method - methodIsNotAuthorized():
[exec] main, WRITE: TLSv1 Application Data, length = 242
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 1040
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 1040
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 1040
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 1040
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 1040
[exec] p: default-threadpool; w: 3, READ: TLSv1 Application Data, length = 520
[exec] Got expected AccessException!
[exec] Generating report at /Users/vbkumarjayanti/Documents/workspace/SQE/appserver-sqe/test_results.xml
[exec]
[exec]
[exec] -----------------------------------------
[exec] - CertificateRealmPerApp-AppLevel-Test2.testIsCallerExcepted(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test1..testIsCallerIsInRole(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test4.Calling-Not-authorized-method: PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test3.Calling-authorized-method: PASS -
[exec] -----------------------------------------
[exec] Total PASS: 4
[exec] Total FAIL: 0
[exec] Total DNR: 0
[exec] -----------------------------------------

checkReporting-common:


sonialiu added a comment - 24/Jan/11 09:47 PM

I installed the glassfish.zip build from the location
http://gf-hudson.us.oracle.com/hudson/view/GFv3%20Trunk/job/gf-trunk-build-continuous/

and ran the test on another solaris machine, I still got the same failure:

[exec] p: default-threadpool; w: 3, handling exception: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] p: default-threadpool; w: 3, SEND TLSv1 ALERT: fatal, description = unexpected_message
[exec] p: default-threadpool; w: 3, WRITE: TLSv1 Alert, length = 2
[exec] p: default-threadpool; w: 3, called closeSocket()
[exec] Got Exception!!! All tests marked as failed!
[exec] java.rmi.MarshalException: CORBA COMM_FAILURE 1330446339 Maybe; nested exception is:
[exec] org.omg.CORBA.COMM_FAILURE: FINE: IOP00410003: Write error sent vmcid: OMG minor code: 3 completed: Maybe
[exec] at com.sun.corba.ee.impl.javax.rmi.CORBA.Util.mapSystemException(Util.java:259)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:213)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:152)
[exec] at com.sun.corba.ee.impl.presentation.rmi.codegen.CodegenStubBase.invoke(CodegenStubBase.java:227)
[exec] at com.sun.s1peqe.security.realmperapp._SecAuthTestRemoteHome_DynamicStub.create(com/sun/s1peqe/security/realmperapp/_SecAuthTestRemoteHome_DynamicStub.java)
[exec] at com.sun.s1peqe.security.realmperapp.RealmPerAppTestClient.doTests(RealmPerAppTestClient.java:63)
[exec] at com.sun.s1peqe.security.realmperapp.RealmPerAppTestClient.main(RealmPerAppTestClient.java:37)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[exec] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[exec] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[exec] at java.lang.reflect.Method.invoke(Method.java:597)
[exec] at org.glassfish.appclient.client.acc.AppClientContainer.launch(AppClientContainer.java:432)
[exec] at org.glassfish.appclient.client.AppClientFacade.launch(AppClientFacade.java:182)
[exec] at org.glassfish.appclient.client.AppClientGroupFacade.main(AppClientGroupFacade.java:65)
[exec] Caused by: org.omg.CORBA.COMM_FAILURE: FINE: IOP00410003: Write error sent vmcid: OMG minor code: 3 completed: Maybe
[exec] at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[exec] at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
[exec] at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
[exec] at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
[exec] at com.sun.corba.ee.spi.orbutil.logex.corba.CorbaExtension.makeException(CorbaExtension.java:248)
[exec] at com.sun.corba.ee.spi.orbutil.logex.corba.CorbaExtension.makeException(CorbaExtension.java:95)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator.handleFullLogging(WrapperGenerator.java:387)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator.access$400(WrapperGenerator.java:107)
[exec] at com.sun.corba.ee.spi.orbutil.logex.WrapperGenerator$2.invoke(WrapperGenerator.java:511)
[exec] at com.sun.corba.ee.spi.orbutil.proxy.CompositeInvocationHandlerImpl.invoke(CompositeInvocationHandlerImpl.java:99)
[exec] at $Proxy34.writeErrorSend(Unknown Source)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.sendWithoutLock(SocketOrChannelConnectionImpl.java:999)
[exec] at com.sun.corba.ee.impl.encoding.BufferManagerWriteStream.sendFragment(BufferManagerWriteStream.java:151)
[exec] at com.sun.corba.ee.impl.encoding.BufferManagerWriteStream.sendMessage(BufferManagerWriteStream.java:165)
[exec] at com.sun.corba.ee.impl.encoding.CDROutputObject.finishSendingMessage(CDROutputObject.java:200)
[exec] at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.finishSendingRequest(CorbaMessageMediatorImpl.java:274)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete1(CorbaClientRequestDispatcherImpl.java:401)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientRequestDispatcherImpl.marshalingComplete(CorbaClientRequestDispatcherImpl.java:368)
[exec] at com.sun.corba.ee.impl.protocol.CorbaClientDelegateImpl.invoke(CorbaClientDelegateImpl.java:273)
[exec] at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:200)
[exec] ... 12 more
[exec] Caused by: javax.net.ssl.SSLException: Connection has been shutdown: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkEOF(SSLSocketImpl.java:1293)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.checkWrite(SSLSocketImpl.java:1305)
[exec] at com.sun.net.ssl.internal.ssl.AppOutputStream.write(AppOutputStream.java:43)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.write(SocketOrChannelConnectionImpl.java:707)
[exec] at com.sun.corba.ee.impl.encoding.CDROutputObject.writeTo(CDROutputObject.java:234)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.sendWithoutLock(SocketOrChannelConnectionImpl.java:985)
[exec] ... 20 more
[exec] Caused by: javax.net.ssl.SSLKeyException: RSA premaster secret error
[exec] at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(RSAClientKeyExchange.java:97)
[exec] at com.sun.net.ssl.internal.ssl.ClientHandshaker.serverHelloDone(ClientHandshaker.java:744)
[exec] at com.sun.net.ssl.internal.ssl.ClientHandshaker.processMessage(ClientHandshaker.java:238)
[exec] at com.sun.net.ssl.internal.ssl.Handshaker.processLoop(Handshaker.java:593)
[exec] at com.sun.net.ssl.internal.ssl.Handshaker.process_record(Handshaker.java:529)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:893)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.performInitialHandshake(SSLSocketImpl.java:1138)
[exec] at com.sun.net.ssl.internal.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:753)
[exec] at com.sun.net.ssl.internal.ssl.AppInputStream.read(AppInputStream.java:75)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.readFully(SocketOrChannelConnectionImpl.java:604)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.read(SocketOrChannelConnectionImpl.java:439)
[exec] at com.sun.corba.ee.impl.protocol.giopmsgheaders.MessageBase.readGIOPHeader(MessageBase.java:139)
[exec] at com.sun.corba.ee.impl.protocol.giopmsgheaders.MessageBase.readGIOPMessage(MessageBase.java:127)
[exec] at com.sun.corba.ee.impl.transport.CorbaContactInfoBase.createMessageMediator(CorbaContactInfoBase.java:147)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.readBits(SocketOrChannelConnectionImpl.java:362)
[exec] at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.read(SocketOrChannelConnectionImpl.java:339)
[exec] at com.sun.corba.ee.impl.transport.ReaderThreadImpl.doWork(ReaderThreadImpl.java:112)
[exec] at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.performWork(ThreadPoolImpl.java:497)
[exec] at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:540)
[exec] Caused by: java.security.NoSuchAlgorithmException: SunTlsRsaPremasterSecret KeyGenerator not available
[exec] at javax.crypto.KeyGenerator.<init>(DashoA13*..)
[exec] at javax.crypto.KeyGenerator.getInstance(DashoA13*..)
[exec] at com.sun.net.ssl.internal.ssl.JsseJce.getKeyGenerator(JsseJce.java:223)
[exec] at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(RSAClientKeyExchange.java:89)
[exec] ... 18 more
[exec] main, called close()
[exec] main, called closeInternal(true)
[exec] Generating report at /export/sonia/appserver-sqe/test_results.xml
[exec]
[exec]
[exec] -----------------------------------------
[exec] - CertificateRealmPerApp-AppLevel-Test2.testIsCallerIsExcepted(): FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test1.testIsCallerIsInRole(): FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test4.Calling-Not-authorized-method: FAIL -
[exec] - CertificateRealmPerApp-AppLevel-Test3.Calling-authorized-method: FAIL -
[exec] -----------------------------------------
[exec] Total PASS: 0
[exec] Total FAIL: 4
[exec] Total DNR: 0


kumarjayanti added a comment - 25/Jan/11 02:32 AM

i could reproduce the problem on the system you have pointed me to. However it is not reproducable on my system.

The main reason is :

Caused by: java.security.NoSuchAlgorithmException: SunTlsRsaPremasterSecret KeyGenerator not available
[exec] at javax.crypto.KeyGenerator.<init>(DashoA13*..)
[exec] at javax.crypto.KeyGenerator.getInstance(DashoA13*..)
[exec] at com.sun.net.ssl.internal.ssl.JsseJce.getKeyGenerator(JsseJce.java:223)
[exec] at com.sun.net.ssl.internal.ssl.RSAClientKeyExchange.<init>(RSAClientKeyExchange.java:89)
[exec] ... 18 more

And this basically means a JDK configuration problem. The problem is not on the server right now, it is on the client side. Not sure if appclient has changed something, but like i said, i don't see this problem on my system.

Can you modify the client ant scripts (run-pe target) to have the following explicit jvm option:

-Djava.ext.dirs=/export/sonia/jdk1.6.0_23/jre/lib/ext

And then can you show me the -verbose output of the run.


Nithya Ramakrishnan added a comment - 25/Jan/11 03:30 AM

Sonia,

We edited ssl/clientcert/build.xml to add -Djava.ext.dirs=/export/sonia/jdk1.6.0_23/jre/lib/ext in the run-pe target. Now all the tests pass:

[exec] -----------------------------------------
[exec] - CertificateRealmPerApp-AppLevel-Test2.testIsCallerExcepted(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test1..testIsCallerIsInRole(): PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test4.Calling-Not-authorized-method: PASS -
[exec] - CertificateRealmPerApp-AppLevel-Test3.Calling-authorized-method: PASS -
[exec] -----------------------------------------
[exec] Total PASS: 4
[exec] Total FAIL: 0
[exec] Total DNR: 0
[exec] -----------------------------------------

If you have observed this to be working in b37 without any changes, and if the test cases have not been modified, it could be that some change in the appclient could have caused this.


sonialiu added a comment - 25/Jan/11 11:17 AM

Since we did not change the test code between b37-b38, as per Nithya, the problem could come from appclient. Tim, could you please take a look at this issue?


Tim Quinn added a comment - 25/Jan/11 12:58 PM

Sigh.

There might be a problem in the app client code for handling AS_JAVA or JAVA_HOME.

The test works on my system but I use a Mac where the JDK home and the JRE home are essentially the same. But that's not true in general.

Sonia, did you specify AS_JAVA in the $installDir/config/asenv.conf file? Or did you specify only JAVA_HOME? (I see from your instructions for reproducing the problem that you seem to specify JAVA_HOME.)


sonialiu added a comment - 25/Jan/11 01:30 PM

Thanks Tim for looking at the issue.
We only set the JAVA_HOME as env. variable when running the SQE test, we don't set the AS_JAVA in the asenv.conf.


Tim Quinn added a comment - 25/Jan/11 01:51 PM

I have a fix in my workspace that works on my Mac OS X system.

I have sent the affected JAR file to Sonia in hopes that she can try a single quick test on her system.


Tim Quinn added a comment - 25/Jan/11 01:58 PM

How bad is its impact? (Severity)
regression of functionality or performance available in a prior release

How often does it happen? (Frequency)
Any time an app client relies on an extension library in the Java installation directory java.home/lib/ext. (Similar problem for endorsed libs).

How much effort is required to fix it? (Cost)
Minimal - candidate fix is working in my workspace and I have asked Sonia to verify that it works in her environment.

What is the risk of fixing it? (Risk)
Minimal.

Does a work around for the issue exist? Can the workaround be reasonably employed by the end user?
There is no workaround. The CLIBootstrap class builds the java command which launches the app client container and, in turn, the app client. CLIBootstrap computes the correct setting for java.ext.dirs. It currently uses JAVA_HOME if the user specified it, but it should use the property value java.home instead. The user could conceivably set java.ext.dirs explicitly on the appclient command, but to do so correctly would require adding the GlassFish library directories as well as his/her own or the Java ones. This is too cumbersome and error-prone to serve as a realistic workaround.

If the issue is not fixed should the issue and its workaround (if applicable) be described in the Release Notes?
n/a (no workaround)


Chris Kasso added a comment - 25/Jan/11 01:59 PM

Approved for 3.1


Tim Quinn added a comment - 25/Jan/11 04:30 PM

Fix checked in.

Project: glassfish
Repository: svn
Revision: 44709
Author: tjquinn
Date: 2011-01-26 00:28:26 UTC
Link:

Log Message:
------------
Fix for 15653

CLIBootstrap generates the java command which launches the app client container. It was incorrectly using the AS_JAVA or JAVA_HOME setting to locate the Java-provided extension and endorsed directories. With these changes it instead (and correctly) uses the java.home system property which does point to the JRE home for locating the lib directory (which in in turn contains ext and endorsed).

Approved: Chris
Reviewed: Tom
Tests: QL, deployment and EJB devtests, SQE test which failed for Sonia (tested on my Mac and on her Solaris system)

Revisions:
----------
44709

Modified Paths:
---------------
trunk/v3/appclient/client/acc/src/main/java/org/glassfish/appclient/client/CLIBootstrap.java