Print

[xtnh]

Hello,

I'm currently working on connecting our Weblogic hosted to JPPF (Version 3.3.1). I successfully installed the JCA Connector, built a job and submited the job.
The task is called successfully on the node, but when I try to lookup the data source from Weblogic JNDI Context (via Hibernate) I get the following exception:

Code: [Select]

java.lang.AssertionError: Failed to generate class for weblogic.jdbc.common.internal.RmiDataSource_1036_WLStub
        at weblogic.rmi.internal.StubGenerator.generateStub(StubGenerator.java:797)
        at weblogic.rmi.internal.StubGenerator.generateStub(StubGenerator.java:786)
        at weblogic.rmi.extensions.StubFactory.getStub(StubFactory.java:74)
        at weblogic.rmi.internal.StubInfo.resolveObject(StubInfo.java:213)
        at weblogic.rmi.internal.StubInfo.readResolve(StubInfo.java:207)
        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 java.io.ObjectStreamClass.invokeReadResolve(ObjectStreamClass.java:1061)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1761)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1328)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:350)
        at weblogic.utils.io.ChunkedObjectInputStream.readObject(ChunkedObjectInputStream.java:197)
        at weblogic.rjvm.MsgAbbrevInputStream.readObject(MsgAbbrevInputStream.java:598)
        at weblogic.utils.io.ChunkedObjectInputStream.readObject(ChunkedObjectInputStream.java:193)
        at weblogic.rmi.internal.ObjectIO.readObject(ObjectIO.java:62)
        at weblogic.rjvm.ResponseImpl.unmarshalReturn(ResponseImpl.java:240)
        at weblogic.rmi.cluster.ClusterableRemoteRef.invoke(ClusterableRemoteRef.java:348)
        at weblogic.rmi.cluster.ClusterableRemoteRef.invoke(ClusterableRemoteRef.java:259)
        at weblogic.jndi.internal.ServerNamingNode_1033_WLStub.lookup(Unknown Source)
        at weblogic.jndi.internal.WLContextImpl.lookup(WLContextImpl.java:405)
        at weblogic.jndi.internal.WLContextImpl.lookup(WLContextImpl.java:393)
        at javax.naming.InitialContext.lookup(InitialContext.java:392)
        at org.hibernate.connection.DatasourceConnectionProvider.configure(DatasourceConnectionProvider.java:75)
        at org.hibernate.connection.ConnectionProviderFactory.newConnectionProvider(ConnectionProviderFactory.java:143)
        at org.hibernate.connection.ConnectionProviderFactory.newConnectionProvider(ConnectionProviderFactory.java:84)
        at org.hibernate.cfg.SettingsFactory.createConnectionProvider(SettingsFactory.java:459)
        at org.hibernate.cfg.SettingsFactory.buildSettings(SettingsFactory.java:91)
        at org.hibernate.cfg.Configuration.buildSettingsInternal(Configuration.java:2833)
        at org.hibernate.cfg.Configuration.buildSettings(Configuration.java:2829)
        at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1840)
        at com.pslife.vertrag.jppfbridge.VertragBearbeitenTask.doRun(VertragBearbeitenTask.java:88)
        at com.pslife.vertrag.jppfbridge.VertragBearbeitenTask.run(VertragBearbeitenTask.java:56)
        at org.jppf.server.node.NodeTaskWrapper.run(NodeTaskWrapper.java:136)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
        at weblogic.rmi.internal.StubGenerator.generateStub(StubGenerator.java:795)
        ... 43 more
Caused by: java.lang.ArrayIndexOutOfBoundsException: 8
        at weblogic.jdbc.common.internal.RmiDataSource_1036_WLStub.ensureInitialized(Unknown Source)
        at weblogic.jdbc.common.internal.RmiDataSource_1036_WLStub.<init>(Unknown Source)
        ... 48 more

The same occures when I try to lookup the data source via a simple JNDI lookup (context.lookup("pslifeds")). If I lookup an EJB there's no such error.

I wrote a main method and executed the task as a simple Java application and everything worked fine.
Hibernate was able to lookup the datasource and the entity has been persisted. Strange! :-(

Here is an example of the task written in Eclipse Xtend (which is similar to Java, so there shouldn't be problems reading the code):

Code: [Select]

@Data
class VertragBearbeitenTask extends JPPFTask {
...

/** called by run() */
def doRun() {

var config = new Configuration
config.setProperty("hibernate.connection.driver_class", "oracle.jdbc.driver.OracleDriver")
config.setProperty("hibernate.connection.datasource", "pslifeds")
config.setProperty("hibernate.dialect", "org.hibernate.dialect.Oracle10gDialect")
config.setProperty("hibernate.transaction.factory_class", "org.hibernate.transaction.JDBCTransactionFactory")
config.setProperty("hibernate.transaction.manager_lookup_class",
"org.hibernate.transaction.WeblogicTransactionManagerLookup")
config.setProperty("hibernate.current_session_context_class", "thread")
config.setProperty("hibernate.cache.provider_class", "org.hibernate.cache.NoCacheProvider")
config.setProperty("hibernate.hbm2ddl.auto", "none")
config.setProperty("hibernate.show_sql", "false")
config.setProperty("jta.UserTransaction", "javax.transaction.UserTransaction")
config.setProperty('hibernate.jndi.java.naming.factory.initial', 'weblogic.jndi.WLInitialContextFactory')
config.setProperty('hibernate.jndi.java.naming.provider.url', 't3://localhost:7001')
config.setProperty('hibernate.jndi.java.naming.security.principal', 'someUser')
config.setProperty('hibernate.jndi.java.naming.security.credentials', 'somePassword')

config.configure
LOG.info('Configuration configured')
val sessionFactory = config.buildSessionFactory
LOG.info('Got session factory')
val currentSession = sessionFactory::currentSession
LOG.info('Got session')
// ... open transaction, call business logic, commit transaction ...
}

def static void main(String[] args) {
// ... create bearbeitungsauftrag
val task = new VertragBearbeitenTask("UUID", '4421', bearbeitungsauftrag)
task.run
}
}

Does anyone have an idea why the tasks' logic works fine outside of the JPPF node, but fails while executed in the JPPF node? The nodes' configuration is the default config and not changed.
Any help is welcome!
If you need more information, please let me know. I will try to provide as much information as I can.

Thanks in advance

Christian

[lolo]

Hello Christian,

Sorry for this late answer. Looking at the exception stack trace, it seems your task is trying to lookup the datasource as if it were running within Weblogic, which is not the case. The root issue seems to be that you are tyring to access a remote JNDI registry, and this fails while trying to generate the corresponding RMI stub.

Please keep in mind that the task is running within the node, which is a separate remote JVM from the one where Weblogic is running. Can you tell us where the node is started, is it on the same machine as the Weblogic instance? If not, you might want to try to change the Hibernate provider URL property so that it points to the actual IP address of the Weblogic host, instead of "localhost". This might explain why it worked in your standalone test.

Can you try that and let us know if this helps?

Thanks,
-Laurent

[xtnh]

Hello Laurent,

the Weblogic server, the JPPF server/driver, the JPPF node and the standalone client are all running on one machine (my developer machine). Changing the url from localhost to my machines' IP address does not have any other effect.
What I don't understand is the fact that the same lookup works in a standalone program (running in a seperate JVM) and doesn't work in a JPPF node. What is the difference?

As far as I know is the following example the correct way to lookup a remote jndi resource, but one might correct me.

Code: [Select]

import java.util.Properties;

import javax.naming.InitialContext;
import javax.sql.DataSource;

public class RemoteLookup {

    public static void main(final String[] args) throws Exception {
        Properties properties = new Properties();
        properties.put("java.naming.factory.initial", "weblogic.jndi.WLInitialContextFactory");
        properties.put("java.naming.provider.url", "t3://localhost:7001"); // works with IP address too
        properties.put("java.naming.security.principal", "someUser");
        properties.put("java.naming.security.credentials", "somePassword");
        InitialContext context = new InitialContext(properties);
        DataSource lookup = (DataSource) context.lookup("pslifeds"); // doesn't fail
        System.out.println(lookup); // doesn't fail
    }

}

Is there a better way to lookup the DataSource?

Btw. all programs (Weblogic, JPPF driver, JPPF node and standalone client) are executed with the same JDK (I thought that it might be a problem if the Java versions are different).

Christian

[lolo]

Hi Christian,

The major difference between your standalone test and running in the node is how class loading is done.
So I'm suspecting this would be our main culprit here. Is there any chance you could test in the node scenario, but with the Weblogic / Hibernate classes in the node's classpath this time?
You can configure the node's classpath in its configuration file: jppf.jvm.options = -server -Xmx512m -cp C:/my/path/to/weblogic/weblogic.jar
You can add multiple -cp options if you want to, or use the path separator for your OS (':' on Linux, ';' on Windows). Each path you specifiy there will be added to rhe node's main classloader classpath.

Can you do this and let us know if this makes any difference?

Thanks,
-Laurent

[xtnh]

Hi Laurent,

embedding the weblogic.jar brought me one step forward. The task can now lookup the data source. But when trying to get a connection the following error occured:

Code: [Select]

java.lang.ClassFormatError: Incompatible magic value 1347093252 in class file weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface
        at java.lang.ClassLoader.defineClass1(Native Method)
        at java.lang.ClassLoader.defineClassCond(ClassLoader.java:631)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:615)
        at java.lang.ClassLoader.defineClass(ClassLoader.java:465)
        at org.jppf.classloader.AbstractJPPFClassLoader.findClass(AbstractJPPFClassLoader.java:157)
        at org.jppf.classloader.AbstractJPPFClassLoader.findClass(AbstractJPPFClassLoader.java:106)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:306)
        at org.jppf.classloader.AbstractJPPFClassLoader.loadClass(AbstractJPPFClassLoader.java:338)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:295)
        at java.lang.ClassLoader.loadClass(ClassLoader.java:247)
        at weblogic.utils.classloaders.GenericClassLoader.loadClass(GenericClassLoader.java:179)
        at java.lang.Class.forName0(Native Method)
        at java.lang.Class.forName(Class.java:247)
        at weblogic.rmi.utils.WLRMIClassLoaderDelegate.loadClass(WLRMIClassLoaderDelegate.java:204)
        at weblogic.rmi.utils.WLRMIClassLoaderDelegate.loadClass(WLRMIClassLoaderDelegate.java:135)
        at weblogic.rmi.utils.Utilities.loadClass(Utilities.java:305)
        at weblogic.rmi.internal.ClientRuntimeDescriptor.computeInterfaces(ClientRuntimeDescriptor.java:232)
        at weblogic.rmi.internal.ClientRuntimeDescriptor.getInterfaces(ClientRuntimeDescriptor.java:147)
        at weblogic.rmi.internal.StubInfo.getInterfaces(StubInfo.java:80)
        at weblogic.rmi.internal.StubGenerator.<init>(StubGenerator.java:85)
        at weblogic.rmi.internal.StubGenerator.hotCodeGenClass(StubGenerator.java:782)
        at weblogic.rmi.internal.StubGenerator.getStubClass(StubGenerator.java:766)
        at weblogic.rmi.internal.StubGenerator.generateStub(StubGenerator.java:793)
        at weblogic.rmi.internal.StubGenerator.generateStub(StubGenerator.java:786)
        at weblogic.rmi.extensions.StubFactory.getStub(StubFactory.java:74)
        at weblogic.rmi.internal.StubInfo.resolveObject(StubInfo.java:254)
        at weblogic.rmi.internal.StubInfo.readResolve(StubInfo.java:199)
        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 java.io.ObjectStreamClass.invokeReadResolve(ObjectStreamClass.java:1061)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1761)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1328)
        at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1946)
        at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1870)
        at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1752)
        at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1328)
        at java.io.ObjectInputStream.readObject(ObjectInputStream.java:350)
        at weblogic.utils.io.ChunkedObjectInputStream.readObject(ChunkedObjectInputStream.java:208)
        at weblogic.rjvm.MsgAbbrevInputStream.readObject(MsgAbbrevInputStream.java:599)
        at weblogic.utils.io.ChunkedObjectInputStream.readObject(ChunkedObjectInputStream.java:204)
        at weblogic.rmi.internal.ObjectIO.readObject(ObjectIO.java:62)
        at weblogic.rjvm.ResponseImpl.unmarshalReturn(ResponseImpl.java:243)
        at weblogic.rmi.cluster.ClusterableRemoteRef.invoke(ClusterableRemoteRef.java:348)
        at weblogic.rmi.cluster.ClusterableRemoteRef.invoke(ClusterableRemoteRef.java:259)
        at weblogic.jdbc.common.internal.RmiDataSource_1036_WLStub.getConnection(Unknown Source)
        at org.hibernate.connection.DatasourceConnectionProvider.getConnection(DatasourceConnectionProvider.java:92)
        at org.hibernate.cfg.SettingsFactory.buildSettings(SettingsFactory.java:114)
        at org.hibernate.cfg.Configuration.buildSettingsInternal(Configuration.java:2833)
        at org.hibernate.cfg.Configuration.buildSettings(Configuration.java:2829)
        at org.hibernate.cfg.Configuration.buildSessionFactory(Configuration.java:1840)
        at com.pslife.vertrag.common.datenzugriff.hibernate.PSLifeHibernateSessionFactory.init(PSLifeHibernateSessionFactory.java:112)
        at com.pslife.vertrag.common.datenzugriff.hibernate.PSLifeHibernateSessionFactory.getSessionFactory(PSLifeHibernateSessionFactory.java:70)
        at com.pslife.vertrag.jppfbridge.VertragBearbeitenTask.doRun(VertragBearbeitenTask.java:87)
        at com.pslife.vertrag.jppfbridge.VertragBearbeitenTask.run(VertragBearbeitenTask.java:56)
        at org.jppf.server.node.NodeTaskWrapper.run(NodeTaskWrapper.java:136)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

While investigating the problem, I found out that the wlfullclient-JAR was packaged in my EAR file (*notgood*). I removed the JAR from the EAR, but the error is the same.
I also put all JARs that are in my EAR into the lib folder of the jppf node, but the error stays.

Christian

[lolo]

Hi Christian,

According to this thread, the magic number 1347093252 is that expected for a zip/jar file, not for a class file. So it seems the JPPF node class loader is not receiving what it is expecting from the JCA client.

Given the qualified name of the class that triggers the error, I'm assuming this is a class generated by Weblogic (RMI stub for a JNDI-bound remote object). Can you confirm this?

To try and find clues as to what is happening, would it be possible for you to turn on DEBUG-level logging for the class loading:
- in the node: in log4j-node.properties, add "log4j.logger.org.jppf.classloader=DEBUG"
- in Weblogic if I remember well you have to set FINEST level for the packages "org.jppf.client" and "org.jppf.classloader"

Otherwise, you might want to consider a different design to accessing the database. In effect, it could make more sense to use a non-J2EE datasource in your tasks, instead of fetching a remote datasource from the application server. For instance, you could use the Apache commons-dbcp API to create a datasource in the node, and use this datasource in your tasks. This would remove the dependency on Weblogic classes altogether. Would this be an acceptable approach?

-Laurent

[xtnh]

Hi Laurent,

today I have to work for another project so I don't have much time to test.
I changed the log levels in node and driver and extracted the lines for the incompatible class.

Node:

Code: [Select]

2013-05-29 15:28:09,775 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClassInURLClasspath(409)]: looking up up resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface] in the URL classpath for JPPFClassLoader[id=2, type=server, uuidPath=[], classpath=]
2013-05-29 15:28:09,775 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClassInURLClasspath(422)]: resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface] not found in the URL classpath for JPPFClassLoader[id=2, type=server, uuidPath=[], classpath=]
2013-05-29 15:28:09,775 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClass(138)]: looking up definition for resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface]
2013-05-29 15:28:09,775 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoaderLifeCycle.loadResource(136)]: loading remote definition for resource [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class]
2013-05-29 15:28:09,776 [DEBUG][org.jppf.classloader.ClassLoaderRequestHandler.run(145)]: sending batch of 1 class loading requests: CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=false, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_REQUEST]]]
2013-05-29 15:28:09,778 [DEBUG][org.jppf.classloader.ClassLoaderRequestHandler.run(151)]: got response CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=false, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]]]
2013-05-29 15:28:09,778 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoaderLifeCycle.loadResource(138)]: remote definition for resource [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] not found
2013-05-29 15:28:09,778 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClass(149)]: definition for resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface] not found
2013-05-29 15:28:09,778 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClassInURLClasspath(409)]: looking up up resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface] in the URL classpath for JPPFClassLoader[id=3, type=client, uuidPath=[461623B2-80C4-6654-FCBD-EBD4DC53E4E8, A9129945-63DF-E94E-9A61-3B8B4F9AA092], classpath=]
2013-05-29 15:28:09,778 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClassInURLClasspath(422)]: resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface] not found in the URL classpath for JPPFClassLoader[id=3, type=client, uuidPath=[461623B2-80C4-6654-FCBD-EBD4DC53E4E8, A9129945-63DF-E94E-9A61-3B8B4F9AA092], classpath=]
2013-05-29 15:28:09,779 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClass(138)]: looking up definition for resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface]
2013-05-29 15:28:09,779 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoaderLifeCycle.loadResource(136)]: loading remote definition for resource [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class]
2013-05-29 15:28:09,779 [DEBUG][org.jppf.classloader.ClassLoaderRequestHandler.run(145)]: sending batch of 1 class loading requests: CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_REQUEST]]]
2013-05-29 15:28:09,791 [DEBUG][org.jppf.classloader.ClassLoaderRequestHandler.run(151)]: got response CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]]]
2013-05-29 15:28:09,791 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoaderLifeCycle.loadResource(138)]: remote definition for resource [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] found
2013-05-29 15:28:09,792 [DEBUG][org.jppf.classloader.AbstractJPPFClassLoader.findClass(154)]: found definition for resource [weblogic.jdbc.rmi.internal.ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface, definitionLength=135405]

Driver:

Code: [Select]

2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.performTransition(75)]: read resource request CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=false, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_REQUEST]]] from node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.processNonDynamic(139)]: resource not found [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] in cache for node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,777 [DEBUG][org.jppf.classloader.ResourceProvider.getResource(126)]: resource [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] not found
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.processNonDynamic(143)]: resource not found [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] in the driver's classpath for node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.performTransition(80)]: sending response CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=false, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]]] to node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from WAITING_NODE_REQUEST to SENDING_NODE_RESPONSE with ops=5 for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4 bytes to output destination, count/size = 4/4 (dl = org.jppf.io.MultipleBuffersLocation@20985fa2)
2013-05-29 15:28:09,777 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 1029 bytes to output destination, count/size = 1029/1029 (dl = org.jppf.io.MultipleBuffersLocation@73ae9565)
2013-05-29 15:28:09,778 [DEBUG][org.jppf.server.nio.classloader.node.SendingNodeResponseState.performTransition(71)]: node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=SENDING_NODE_RESPONSE, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25], response [CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=false, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]]]] sent to the node
2013-05-29 15:28:09,778 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from SENDING_NODE_RESPONSE to WAITING_NODE_REQUEST with ops=1 for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=SENDING_NODE_RESPONSE, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,779 [DEBUG][org.jppf.server.nio.PlainNioObject.read(96)]: read 4 bytes from input source, count/size = 4/4
2013-05-29 15:28:09,779 [DEBUG][org.jppf.server.nio.PlainNioObject.read(99)]: count = 4, size = 4
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.PlainNioObject.read(96)]: read 1163 bytes from input source, count/size = 1163/1163
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.PlainNioObject.read(99)]: count = 1163, size = 1163
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.performTransition(75)]: read resource request CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_REQUEST]]] from node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.processDynamic(181)]: requesting resource JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_REQUEST] from client: SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=IDLE_PROVIDER, resource=null, pendingRequests=0, currentRequest=null, connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8] for node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.classloader.ClassContext.processRequests(199)]: state changing from IDLE_PROVIDER to SENDING_PROVIDER_REQUEST for channel=SelectionKeyWrapper[id=3], state=IDLE_PROVIDER, resource=null, pendingRequests=1, currentRequest=null, connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from IDLE_PROVIDER to SENDING_PROVIDER_REQUEST with ops=5 for channel SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=IDLE_PROVIDER, resource=null, pendingRequests=1, currentRequest=null, connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8]
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.classloader.node.WaitingNodeRequestState.performTransition(84)]: pending responses 1 for node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from WAITING_NODE_REQUEST to IDLE_NODE with ops=0 for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,780 [DEBUG][org.jppf.server.nio.classloader.client.SendingProviderRequestState.performTransition(77)]: provider SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=SENDING_PROVIDER_REQUEST, resource=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, pendingRequests=0, currentRequest=null, connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8] serving new request [weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class] from node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=WAITING_NODE_REQUEST, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,781 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4 bytes to output destination, count/size = 4/4 (dl = org.jppf.io.MultipleBuffersLocation@3067ed13)
2013-05-29 15:28:09,781 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 982 bytes to output destination, count/size = 982/982 (dl = org.jppf.io.MultipleBuffersLocation@76fd9338)
2013-05-29 15:28:09,781 [DEBUG][org.jppf.server.nio.classloader.client.SendingProviderRequestState.performTransition(84)]: request sent to provider SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=SENDING_PROVIDER_REQUEST, resource=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, pendingRequests=0, currentRequest=ResourceRequest[channel=SelectionKeyWrapper[id=6], resource=JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=PROVIDER_REQUEST]], connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8] from node ResourceRequest[channel=SelectionKeyWrapper[id=6], resource=JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=PROVIDER_REQUEST]], resource: weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class
2013-05-29 15:28:09,781 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from SENDING_PROVIDER_REQUEST to WAITING_PROVIDER_RESPONSE with ops=1 for channel SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=SENDING_PROVIDER_REQUEST, resource=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, pendingRequests=0, currentRequest=ResourceRequest[channel=SelectionKeyWrapper[id=6], resource=JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=PROVIDER_REQUEST]], connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8]
2013-05-29 15:28:09,782 [DEBUG][org.jppf.server.nio.PlainNioObject.read(96)]: read 4 bytes from input source, count/size = 4/4
2013-05-29 15:28:09,782 [DEBUG][org.jppf.server.nio.PlainNioObject.read(99)]: count = 4, size = 4
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.PlainNioObject.read(96)]: read 136424 bytes from input source, count/size = 136424/136424
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.PlainNioObject.read(99)]: count = 136424, size = 136424
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.classloader.client.WaitingProviderResponseState.performTransition(77)]: read response from provider: SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=WAITING_PROVIDER_RESPONSE, resource=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, pendingRequests=0, currentRequest=ResourceRequest[channel=SelectionKeyWrapper[id=6], resource=JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=PROVIDER_REQUEST]], connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8], sending to node SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=IDLE_NODE, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25], resource: weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.classloader.client.WaitingProviderResponseState.performTransition(87)]: client SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=WAITING_PROVIDER_RESPONSE, resource=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, pendingRequests=0, currentRequest=ResourceRequest[channel=SelectionKeyWrapper[id=6], resource=JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=PROVIDER_REQUEST]], connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8] sending response JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE] to node SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=IDLE_NODE, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from IDLE_NODE to NODE_WAITING_PROVIDER_RESPONSE with ops=5 for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=IDLE_NODE, resource=null, pendingResponses=1, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,783 [DEBUG][org.jppf.server.nio.classloader.node.NodeWaitingProviderResponseState.performTransition(79)]: node[id=6] got response for resource JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]
2013-05-29 15:28:09,783 [WARN ][org.jppf.server.nio.StateTransitionManager.transitionChannel(134)]: unauthorized transition from WAITING_PROVIDER_RESPONSE to IDLE_PROVIDER with ops=1 for channel SelectionKeyWrapper[id=3, DE-ADN-45V96S1.adesso.local:49961, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=3], state=WAITING_PROVIDER_RESPONSE, resource=null, pendingRequests=0, currentRequest=null, connectionUuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8_1, type=client, peer=false, uuid=461623B2-80C4-6654-FCBD-EBD4DC53E4E8]
2013-05-29 15:28:09,784 [DEBUG][org.jppf.server.nio.classloader.node.NodeWaitingProviderResponseState.sendResponse(98)]: preparing to send the response for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=NODE_WAITING_PROVIDER_RESPONSE, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,784 [DEBUG][org.jppf.server.nio.StateTransitionManager.transitionChannel(135)]: transition from NODE_WAITING_PROVIDER_RESPONSE to SENDING_NODE_RESPONSE with ops=5 for channel SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=1, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=NODE_WAITING_PROVIDER_RESPONSE, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25]
2013-05-29 15:28:09,784 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4 bytes to output destination, count/size = 4/4 (dl = org.jppf.io.MultipleBuffersLocation@4b33650d)
2013-05-29 15:28:09,784 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 3603 bytes to output destination, count/size = 3603/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,784 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 7699/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,785 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 11795/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,785 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 15891/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,785 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 19987/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,785 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 24083/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,786 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 28179/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,786 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 32275/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,786 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 36371/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,786 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 40467/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,786 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 44563/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,787 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 48659/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,787 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 52755/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,787 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 56851/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,787 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 60947/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,788 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 65043/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,788 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 69139/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,788 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 73235/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,788 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 77331/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,788 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 81427/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 85523/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 89619/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 93715/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 97811/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 101907/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,789 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 106003/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 110099/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 114195/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 118291/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 122387/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 126483/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 130579/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,790 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 4096 bytes to output destination, count/size = 134675/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,791 [DEBUG][org.jppf.server.nio.PlainNioObject.write(120)]: wrote 1930 bytes to output destination, count/size = 136605/136605 (dl = org.jppf.io.MultipleBuffersLocation@1b2f5f0d)
2013-05-29 15:28:09,791 [DEBUG][org.jppf.server.nio.classloader.node.SendingNodeResponseState.performTransition(71)]: node: SelectionKeyWrapper[id=6, 127.0.0.1:49976, readyOps=4, keyOps=0, context=channel=SelectionKeyWrapper[id=6], state=SENDING_NODE_RESPONSE, resource=null, pendingResponses=0, type=node, peer=false, uuid=B3135D03-66F9-1829-EE47-F4ECE2322C25], response [CompositeResourceWrapper[resources=[JPPFResourceWrapper[dynamic=true, name=weblogic/jdbc/rmi/internal/ConnectionImpl_weblogic_jdbc_wrapper_JTAConnection_weblogic_jdbc_wrapper_XAConnection_oracle_jdbc_driver_LogicalConnection_RemoteInterface.class, state=NODE_RESPONSE]]]] sent to the node

I didn't get the weblogic to log on a finer level quickly so I have to do that later. But maybe these logs will help. Please let me know if you need more information.

The approach not to use the weblogic data source is currently not an option. We would have to provide the database user credentials to the node to initialize the data source. The problem is that we still don't know the credentials in production environment, because the weblogic administrators configured the datasource.
In my local environment this is no problem, but that won't work in production.
The basic idea is to just have only one data source configured that is responsible for database connection handling.

If there is really no way to do this in JPPF we will consider to change our position, but until now I'm confident that there are ways to solve the problem.

Thanks

Christian

[lolo]

Hi Christian,

Thanks for the additional info.
There is possibly a configuration issue for the node used as a standalone Weblogic client. I found this related article particularly insightful in this regard. One of the interesting points is that the node should not have weblogic.jar in its classpath, but rather wlclient.jar or wlfullclient.jar (which has to be generated as per the article instructions).

I will give it a try on my side, I have a Weblogic 10.3 (aka 11g) that I can use. It will take some time, though, and I may not have any results before early next week. I'll let you know of my findings.

Sincerely,
-Laurent

[lolo]

Hi Christian,

I was able to setup a test webapp in my Weblogic 11g. I was able to access a data source defined in WL and use it to make queries.
What did the trick was to generate the wlfullclient.jar and add it to the JPPF driver's classpath (to avoid deploying on each node individually).
Apparently, the thin client (wlclient.jar) transparently uses IIOP behind the scene, even when you specifiy a t3: address in the provider url, which causes problems with the remote class loading. The full client actually uses the t3 protocol, and this works as far as my tests went.

In my test I used JDBC directly, not Hibernate, so you may have Hibernate-related issues, but I believe this is a nice step forward.

-Laurent

[xtnh]

Hi Laurent,

thanks a lot for your investigations. I was really helpless.
I will test the setup with the wlfullclient in the drivers' classpath today and let you know if that does the trick.

Thanks!

Christian

[xtnh]

Hi Laurent,

I still get the error with JDBC and also with Hibernate.
I built the wlfullclient.jar with wljarbuilder and put it into the driver's lib-folder. The node's classpath is configured as distributed by JPPF (=default).
I configured an additional Oracle data source which is not a XA data source, but that didn't do the trick too.

How did you setup the database and for what database did you do that?
Maybe I can reproduce your setup to get an test environment with no errors. Or just to find some differences to my setup.

Thanks

Christian

[xtnh]

How did you setup the database and for what database did you do that?

Sorry, I meant "How did you setup the data source and for what database did you do that?".
I did setup a Derby DB and created a new data source, but the problem still stays the same.

Christian

[lolo]

Hi Christian,

I am using MySQL 5.0 to do my test. I don't think which database is used is really important, since whateever is used on the node side are proxies generated by Weblogic for java.sql.* and javax.sql.* interfaces. Here the data source setup as read form the WL confif file:

Code: [Select]

<?xml version='1.0' encoding='UTF-8'?>
<jdbc-data-source xmlns="http://xmlns.oracle.com/weblogic/jdbc-data-source" ...>
  <name>JPPF test DS</name>
  <jdbc-driver-params>
    <url>jdbc:mysql://localhost:3306/testjppf</url>
    <driver-name>com.mysql.jdbc.Driver</driver-name>
    <properties>
      <property>
        <name>user</name>
        <value>testjppf</value>
      </property>
    </properties>
    <password-encrypted>...</password-encrypted>
  </jdbc-driver-params>
  <jdbc-connection-pool-params>
    <test-table-name>SQL SELECT 1</test-table-name>
  </jdbc-connection-pool-params>
  <jdbc-data-source-params>
    <jndi-name>jdbc/jppfDS</jndi-name>
    <global-transactions-protocol>OnePhaseCommit</global-transactions-protocol>
  </jdbc-data-source-params>
</jdbc-data-source>
In any case, I have uploaded my test project, which you can get from here: http://www.jppf.org/private/wl-test/x-weblogic.zip
It is normally self-contained and you can build it with the included Ant script. The .ear is generated in x-weblogic/build. It also includes the relevant server configuration, along with the DS definition file in "weblogic-config/jdbc". There is also a SQL file with the DDL to create the required table and some insert statements to populate it.

To run this sample, deploy TestWeblogic.ear to your WL instance, then browse to http://localhost:7001/weblogic_test. On the page click submit to send a JPPF job. If it works properly you will get back to the same page with an "execution successful" message, otherwise a stack trace will be displayed.

The JPPF task prints a few things in the node console. Here is an example of what I got:

Code: [Select]

node process id: 3188
Attempting connection to the class server at 192.168.1.14:11111
Reconnected to the class server
JPPF Node management initialized
Attempting connection to the node server at 192.168.1.14:11111
Reconnected to the node server
Node successfully initialized
got datasource ClusterableRemoteRef(-6209956585212552390S:127.0.0.1:[7001,7001,-1,-1,-1,-1,-1]:jppf:AdminServer [-6209956585212552390S:127.0.0.1:[7001,7001,-1,-1,-1,-1,-1]:jppf:AdminServer/287])/287
got connection weblogic.jdbc.rmi.SerialConnection_weblogic_jdbc_rmi_internal_ConnectionImpl_weblogic_jdbc_wrapper_PoolConnection_com_mysql_jdbc_JDBC4Connection_1035_WLStub@1
customer id=1, name=John Smith, age=45
customer id=2, name=Jane Doe, age=35
Please give it a try and let me know of the outcome.

Sincerely,
-Laurent

[xtnh]

Hello Laurent,

sorry for not answering for a long time. There have been plenty of other tasks that caused the late answer (and of course my forgetfulness plays a small part in this too).
In our team we tried out your example application, but it doesn't work on several developer machines.
One of our team members wrote down what he did (see attachment). Can you review if we missed something?
The only obvious difference is that we use Weblogic 10.3.6 instead of 10.3.5.0.

Thanks

Christian

[lolo]

Hi Christian,

Unfortunately, I'm still unable to reproduce the ClassFormatError. I even tried with a remote Oracle datasource instead of MySQL, to no effect. In my environment the task is accessing the datasource without any issue, and is then able to query the database.

As I had mentioned previously, we will need more information to figure out what's going on. To this effect, we'll need additional logs from the node and the JCA connector.
To enable debug logging of the class loader in the node: in config/log4j-node.properties, add the following line: log4j.logger.org.jppf.classloader=DEBUG
On the Weblogic side, we need somehow use the finest possible level for the packages (and subpackages) org.jppf.client.* and org.jppf.jca.*. I have no idea how to do that in Weblogic, so on my side I just added the slf4j and log4j libraries to the domain's "lib" folder, along with a log4.properties packaged in a jar (attached in this post) and that generated the log file I needed.

Could you please configure the logging appropriately, run the failing test again, and post the resulting jca and node logs?

Thanks a lot,
-Laurent

[xtnh]

Hi Laurent,

thanks for your answer. I wasn't able to change Weblogics log level, too. Your way with slf4j and log4j works for me, so I was able to get the log files (see attachments).
Unfortunatly I still get the mentioned error.

I executed the following steps:
- full installation of domain, JCA connector and application as described in my PDF
- copied the log-jars from jppf-node to lib folder
- put your log-props-jar to lib folder
- started weblogic
- started jppf-driver
- started jppf-node
- pressed "submit"-button in test-app

Anything I forgot? Do you need more information?

Thanks

Christian

[lolo]

Hi Christian,

Thank you very much for providing the logs.
One difference I noted between your logs and mine is that on your side the oracle connection class is actually requested and found on the jppf client side, whereas in my environment, it is not found, and thus I suppose the wlfullclient code is generating it on the node side.

I then decided to use the exact same setup as you described in the pdf, and then I was able to reproduce the ClassFormatError.
I'm suspecting that some difference in the Weblogic JVM options is causing this, and I'm currently investigating it.

For reference, with my initial setup, the JVM was launched like this:

Code: [Select]

C:\java\jdk1.6.0_x64\bin\java -client
-Xmx1024m -XX:MaxPermSize=256m
-Dweblogic.Name=AdminServer
-Djava.security.policy=C:\Tools\Oracle\WLSERV~1.3\server\lib\weblogic.policy
-Xverify:none
-da
-Dplatform.home=C:\Tools\Oracle\WLSERV~1.3 -Dwls.home=C:\Tools\Oracle\WLSERV~1.3\server -Dweblogic.home=C:\Tools\Oracle\WLSERV~1.3\server
-Dweblogic.management.discover=true
-Dwlw.iterativeDev=
-Dwlw.testConsole=
-Dwlw.logErrorsToConsole=
-Dweblogic.ext.dirs=C:\Tools\Oracle\patch_wls1035\profiles\default\sysext_manifest_classpath
-Xdebug -Xnoagent -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n -Duser.language=en -Duser.country=US
-Dlog4j.configuration=log4j.properties
weblogic.Server
In the new setup (similar to yours) they look like this:

Code: [Select]

C:\java\JDK16~1.0_X\bin\java -client
-Xms256m -Xmx512m -XX:CompileThreshold=8000 -XX:PermSize=48m -XX:MaxPermSize=256m
-Dweblogic.Name=myserver
-Djava.security.policy=C:\Tools\WLS103~1\wlserver\server\lib\weblogic.policy
-Xverify:none
-da
-Dplatform.home=C:\Tools\WLS103~1\wlserver -Dwls.home=C:\Tools\WLS103~1\wlserver\server -Dweblogic.home=C:\Tools\WLS103~1\wlserver\server
-Dweblogic.management.discover=true
-Dwlw.iterativeDev=
-Dwlw.testConsole=
-Dwlw.logErrorsToConsole=
weblogic.Server
Please note that I also had to set -XX:MaxPermSize=256m instead of 128m to get rid of OutOfMemoryErrior: PermGen space in Weblogic

I'll get back to you as soon as I have something new.

Sincerely,
-Laurent

[lolo]

Hello Christian,

I finally got to the bottom of this issue.
After adding more detailed traces, I found out that Weblogic have a strange implementation of their class loader associated with JCA connectors.

The detailed explanation:
- when the node sends a class loading request for the jdbc connection wrapper class (weblogic/jdbc/rmi/internal/..._oracle_jdbc_driver_LogicalConnection_RemoteInterface.class), the JPPF code looks it up using the Weblogic class loader for the JCA connector (a weblogic.utils.classloaders.ChangeAwareClassLoader), using the getResource() method, which returns a single URL pointing to the class file.
- for this connection class, getResource() actually returns "file:/<WL_HOME>/modules/com.bea.core.utils.wrapper_1.4.0.0.jar". So this is what was returned to the node. It also explains both the ClassFormatError and the "Incompatible magic value 1347093252" message, since 1347093252 is the 4-bytes signature of a zip (or jar) file.
- however, when using the getResources() method to lookup the same class, this returns an empty Enumeration of URLs, which is the expected behavior. This will cause the node class loader to throw a ClassNotFoundException, which is caught by the Weblogic code in wlfullclient.jar, and then the Weblogic code will actually generate this class.

Additionally, with Weblogic v10.3.6, I also had to add the Oracle ojdbc6.jar to the node or driver's classpath, otherwise I would get a " java.lang.NoClassDefFoundError: oracle/sql/BfileDBAccess". I actually had to do this both when within a JPPF node or in a standalone Java program.

To fix this issue, I patched the code that performs classes lookup on the JPPF client side, and uploaded the patched weblogic .rar there: http://www.jppf.org/private/3.3.3/jppf_ra_Weblogic.rar
Can you give it a try and let us know if that resolves the problem?

Sincerely,
-Laurent

[xtnh]

Hello Laurent,

we put the oracle driver into the nodes' lib folder and replaced the JCA connector as described.
The result is that we got your example app running without errors  . Thanks a lot!!!

The next step is to test our application with this setup. Unfortunately I will not have the time to test it before monday/tuesday in the next week, but I will post the results here.

Are there any plans to build a patch release if the fix is approved a second time?
For now it's no problem to work with the patched rar, but in the future I would prefer using a regular and stable release.

Thanks

Christian

[lolo]

Hello Christian,

I will deliver, early next week, an official patch for v3.3.3, which will contain the exact same rar file as you are currently testing.
The fix will of course be included in the next JPPF maintenance release (v3.3.6) and in the current v4.0 development branch.

Sincerely,
-Laurent

[lolo]

Hi Christian,

I wanted to let you know that we have delivered patch 02 for JPPF 3.3.3, which contains the fixed .rar file for Weblogic.

Sincerely,
-Laurent

[xtnh]

Hi Laurent,

I'm now able to get the datasource as well as a database connection from the weblogic.
There are still some Hibernate config problems, but that's something beyond JPPF (- or rather I hope that it's beyond JPPF !).

Many thanks for your assistance!

Christian

[xtnh]

Hi Laurent,

after solving my Hibernate problems (which were partially classloader/classpath related) everything works fine.
Anyway I still have to put some jar files into the lib folder of my driver (including ojdbc6 etc., but excluding wlfullclient.jar!!!).

Is there a chance to get the whole thing running without any additional jar files than the once coming with the jppf distribution?

Sincerly

Christian

[lolo]

Hello Christian,

The fact that wlfullclient.jar and ojdbc6.jar are needed in the classpath of the node or driver has nothing to do with JPPF. They are also needed if you try the same thing with a standalone Java application. The WL client is needed because that's how Weblogic remote JDBC is designed. For the Oracle jar, I really don't know. It's not needed with WL 10.3.5, and the problem you had did not occur in that version.

Furthermore, the class loading issue was happening because the Weblogic class loader does not behave properly. Clearly, there have been changes in 10.3.6 that made all this happen. If you have a support contract with Oracle, you might want to report this issue. As a customer, you will probably have more chances that they will listen and eventually patch or fix it.

Sincerely,
-Laurent