[regression] failed to get connection with OAUTH marshaling failure

[glassfishrobot]

tx prorogation with appclient tests failed to get connection to oracle database.

[echo] WARNING: RAR5038:Unexpected exception while creating resource for pool pooltxp. Exception : javax.resource.spi.ResourceAllocationException: Connection could not be allocated because: OAUTH marshaling failure.

The same tests passed on glassfish-3.1-b31.zip promoted on 11_30_2010.

To reproduce the problem: Please refer to this issue for test setup http://java.net/jira/browse/GLASSFISH-14918 Run test by doing do "ant oracle4 all_ac_sql_nodsd" in appserver-sqe/pe/ejb/ejb30/txpropagation

This failure blocks me to verify the fix of 14918.

Environment

RHL5

Affected Versions

[3.1]

[glassfishrobot]

• Issue Imported From: https://github.com/javaee/glassfish/issues/15004
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To: @tjquinno
• Original Issue Closed By:@glassfishrobot

[glassfishrobot]

@glassfishrobot Commented sherryshen said: The stacktrace is near utx.begin() in test client. [echo] at com.sun.enterprise.transaction.UserTransactionImpl.begin(UserTransactionImpl.java:165) [echo] at ejb30.txpropagation.client.TestClient.doTest(TestClient.java:80)

appserver-sqe/pe/ejb/ejb30/txpropagation/client/TestClient.java_nodsd public class TestClient { private DataSource ds; public static void main (String[] args) { private static @EJB Sful sful; public void doTest(String suite, boolean commit) { // ... try { // ... UserTransaction utx = (UserTransaction) (new javax.naming.InitialContext()).lookup("java:comp/UserTransaction"); ds = (DataSource) (new javax.naming.InitialContext()).lookup("jdbc/txp"); utx.begin(); // line 80 in above stack trace. connection = ds.getConnection();

runclient-common: [echo] Executing appclient at /export/hudson/workspace/sherry-ejbdbg-oracle/appserver-sqe/pe/ejb/ejb30/txpropagation [echo] Dec 5, 2010 9:18:16 PM org.glassfish.appclient.client.acc.AppclientCommandArguments warnAboutPasswordUsage [echo] WARNING: ACC013: The -password option is deprecated and will likely be removed in a future release. Please use -passwordfile or let the app client container prompt for the username and/or password if they are needed to access a remote resource. [echo] Dec 5, 2010 9:18:18 PM com.sun.logging.LogDomains$1 log [echo] WARNING: ACC001: Using the only client [ejb30-txpropagation-client] with main class [ejb30.txpropagation.client.TestClient] in file:/export/hudson/workspace/sherry-ejbdbg-oracle/appserver-sqe/build/pe/i386_apg-sqe1_Linux/ejb30-txpropagation/archive/ejb30-txpropagationAppClient.jar even though it does not match the specified main class name null or client name ejb30-txpropagationClient [echo] Dec 5, 2010 9:18:18 PM com.sun.logging.LogDomains$1 log [echo] INFO: DTX5019: Using [com.sun.enterprise.transaction.jts.JavaEETransactionManagerJTSDelegate] as the delegate [echo] WS HOME appserver-sqe [echo] testSuiteID=EJB3-TXPropagation_AC_sql_nodsd [echo] name=mary [echo] AppClient [echo] after SC lookup ejb or AC: sful=ejb30.txpropagation._Sful_Wrapper@424288a4 [echo] Dec 5, 2010 9:18:32 PM org.hibernate.validator.util.Version [echo] INFO: Hibernate Validator 4.1.0.Final [echo] Dec 5, 2010 9:18:32 PM org.hibernate.validator.engine.resolver.DefaultTraversableResolver detectJPA [echo] INFO: Instantiated an instance of org.hibernate.validator.engine.resolver.JPATraversableResolver. [echo] ds=com.sun.gjc.spi.jdbc40.DataSource40@129efd0 [echo] Dec 5, 2010 9:18:33 PM com.sun.logging.LogDomains$1 log [echo] WARNING: RAR5038:Unexpected exception while creating resource for pool pooltxp. Exception : javax.resource.spi.ResourceAllocationException: Connection could not be allocated because: OAUTH marshaling failure [echo] Dec 5, 2010 9:18:33 PM com.sun.logging.LogDomains$1 log [echo] WARNING: RAR5117 : Failed to obtain/create connection from connection pool [ pooltxp ]. Reason : com.sun.appserv.connectors.internal.api.PoolingException: Connection could not be allocated because: OAUTH marshaling failure [echo] Dec 5, 2010 9:18:33 PM com.sun.logging.LogDomains$1 log [echo] WARNING: jdbc.exc_get_conn [echo] java.sql.SQLException: Error in allocating a connection. Cause: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.gjc.spi.base.DataSource.getConnection(DataSource.java:117) [echo] at ejb30.txpropagation.client.TestClient.doTest(TestClient.java:81) [echo] at ejb30.txpropagation.client.TestClient.main(TestClient.java:34) [echo] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [echo] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [echo] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [echo] at java.lang.reflect.Method.invoke(Method.java:597) [echo] at org.glassfish.appclient.client.acc.AppClientContainer.launch(AppClientContainer.java:432) [echo] at org.glassfish.appclient.client.AppClientFacade.launch(AppClientFacade.java:182) [echo] at org.glassfish.appclient.client.AppClientGroupFacade.main(AppClientGroupFacade.java:65) [echo] Caused by: javax.resource.spi.ResourceAllocationException: Error in allocating a connection. Cause: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:310) [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:190) [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:165) [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:160) [echo] at com.sun.gjc.spi.base.DataSource.getConnection(DataSource.java:110) [echo] ... 9 more [echo] Caused by: com.sun.appserv.connectors.internal.api.PoolingException: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.enterprise.resource.pool.datastructure.RWLockDataStructure.addResource(RWLockDataStructure.java:103) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.addResource(ConnectionPool.java:282) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.createResourceAndAddToPool(ConnectionPool.java:1497) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.createResources(ConnectionPool.java:940) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.initPool(ConnectionPool.java:230) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.internalGetResource(ConnectionPool.java:511) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.getResource(ConnectionPool.java:381) [echo] at com.sun.enterprise.resource.pool.PoolManagerImpl.getResourceFromPool(PoolManagerImpl.java:242) [echo] at com.sun.enterprise.resource.pool.PoolManagerImpl.getResource(PoolManagerImpl.java:167) [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.getResource(ConnectionManagerImpl.java:335) [echo] at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:304) [echo] ... 13 more [echo] Caused by: com.sun.appserv.connectors.internal.api.PoolingException: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.enterprise.resource.pool.ConnectionPool.createSingleResource(ConnectionPool.java:920) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.createResource(ConnectionPool.java:1181) [echo] at com.sun.enterprise.resource.pool.datastructure.RWLockDataStructure.addResource(RWLockDataStructure.java:98) [echo] ... 23 more [echo] Caused by: com.sun.appserv.connectors.internal.api.PoolingException: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.enterprise.resource.allocator.ConnectorAllocator.createResource(ConnectorAllocator.java:168) [echo] at com.sun.enterprise.resource.pool.ConnectionPool.createSingleResource(ConnectionPool.java:903) [echo] ... 25 more [echo] Caused by: javax.resource.spi.ResourceAllocationException: Connection could not be allocated because: OAUTH marshaling failure [echo] at com.sun.gjc.spi.XAManagedConnectionFactory.createManagedConnection(XAManagedConnectionFactory.java:128) [echo] at com.sun.enterprise.resource.allocator.ConnectorAllocator.createResource(ConnectorAllocator.java:147) [echo] ... 26 more [echo] Caused by: java.sql.SQLException: OAUTH marshaling failure [echo] at oracle.jdbc.driver.T4CTTIoauthenticate.doOAUTH(T4CTTIoauthenticate.java:663) [echo] at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:359) [echo] at oracle.jdbc.driver.PhysicalConnection.(PhysicalConnection.java:531) [echo] at oracle.jdbc.driver.T4CConnection.(T4CConnection.java:221) [echo] at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:32) [echo] at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:503) [echo] at oracle.jdbc.pool.OracleDataSource.getPhysicalConnection(OracleDataSource.java:280) [echo] at oracle.jdbc.xa.client.OracleXADataSource.getPooledConnection(OracleXADataSource.java:466) [echo] at oracle.jdbc.xa.client.OracleXADataSource.getXAConnection(OracleXADataSource.java:154) [echo] at oracle.jdbc.xa.client.OracleXADataSource.getXAConnection(OracleXADataSource.java:99) [echo] at com.sun.gjc.spi.XAManagedConnectionFactory.createManagedConnection(XAManagedConnectionFactory.java:113) [echo] ... 27 more [echo] AppClient [echo] after SC lookup ejb or AC: sful=ejb30.txpropagation._Sful_Wrapper@424288a4 [echo] ds=com.sun.gjc.spi.jdbc40.DataSource40@115e166 [echo] javax.transaction.NotSupportedException: Nested transaction not supported. [echo] at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.begin(JavaEETransactionManagerSimplified.java:811) [echo] at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.begin(JavaEETransactionManagerSimplified.java:799) [echo] at com.sun.enterprise.transaction.UserTransactionImpl.begin(UserTransactionImpl.java:165) [echo] at ejb30.txpropagation.client.TestClient.doTest(TestClient.java:80) [echo] at ejb30.txpropagation.client.TestClient.main(TestClient.java:35) [echo] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [echo] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [echo] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [echo] at java.lang.reflect.Method.invoke(Method.java:597) [echo] at org.glassfish.appclient.client.acc.AppClientContainer.launch(AppClientContainer.java:432) [echo] at org.glassfish.appclient.client.AppClientFacade.launch(AppClientFacade.java:182)

[echo] at org.glassfish.appclient.client.AppClientGroupFacade.main(AppClientGroupFacade.java:65)

[glassfishrobot]

@glassfishrobot Commented sherryshen said: [regression] failed to get connection with OAUTH marshaling failure at glassfish-3.1-b31-12_05_2010.zip

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: Seems to be failing from 1st Dec 2010 nightly build. Seems to be failing only in Appclient container. (Able to acquire connections from same pool/@DSD in an EJB).

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: Further investigation reveals that this behavior is seen from 1st Dec 2010 nightly and related to the appclient script related refactoring changes that were introduced, as revoking them seems to solve the issue.

[glassfishrobot]

@glassfishrobot Commented @tjquinno said: Jagadish and I have exchanged several e-mails off-line.

I cannot reproduce this problem using out-of-the-box nightly builds.

I updated my copy of the sqe directory. I followed the steps described in 14918. In step 7 I get a naming exception (not related to the marshaling error reported here). Step 8 succeeds.

I tried with the Dec. 1 and Dec. 2 nightly builds. Same successful results both times.

But, I was able to trigger the problem by moving the sunjce_provider.jar library out of $JAVA_HOME/lib/ext on my system.

Jagadish, in your test run you had JAVA_HOME defined as

/home/jagadish/installations/jdk6

and the appclient uses JAVA_HOME for setting java.ext.dirs to include the GlassFish extension directories and the Java ones at $JAVA_HOME/lib/ext.

Can you please confirm if /home/jagadish/installations/jdk6/lib/ext exists and contains sunjce_provider.jar?

[glassfishrobot]

@glassfishrobot Commented @tjquinno said: Additional note:

I plan to change the appclient logic so that JAVA_HOME can be defined to point to either the JDK directory or the JRE directory. With this change in place you should not need to change your JAVA_HOME definition.

I would still like to hear if the test works when you (temporarily) change JAVA_HOME to point to the JRE directory.

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: Transferring to Tim who takes care of ACC. Tim has started investigating the issue.

[glassfishrobot]

@glassfishrobot Commented @tjquinno said: Fix checked in.

Project: glassfish Repository: svn Revision: 43549 Author: tjquinn Date: 2010-12-07 22:59:40 UTC Link:

Log Message:

Improve and clean up choice of which Java to use, and of finding the JRE home.

Tests: QL, deployment devtests

Revisions:

43549

Modified Paths:

trunk/v3/appclient/client/acc/src/test/java/org/glassfish/appclient/client/CLIBootstrapTest.java trunk/v3/appclient/client/acc/src/main/java/org/glassfish/appclient/client/CLIBootstrap.java trunk/v3/appclient/client/appclient-scripts/src/main/resources/glassfish/bin/appclient.bat

[glassfishrobot]

@glassfishrobot Commented @h2002044 said: Tim : Sorry, I did not see that you have asked to confirm that pointing to JRE solves the issue. [somehow emails on issue updates are not delivered]

Yes, I tried pointing to JRE and it solves the issue.

[glassfishrobot]

@glassfishrobot Commented This issue was imported from java.net JIRA GLASSFISH-15004

[glassfishrobot]

@glassfishrobot Commented Reported by sherryshen

[glassfishrobot]

@glassfishrobot Commented Marked as fixed on Tuesday, December 7th 2010, 10:57:06 am