9 Replies Latest reply on Oct 4, 2006 4:48 PM by aguizar

    SOAP Fault Exception - BPEL ATM Example

    kvak_tnt

      Hi there!

      I have a big problem with the ATM-Example.
      All the time I want to start the ATM-GUI or start the JUnit-Tests it fails with the following message (bellow the next paragraph)

      Now I have found out that this happens not every time and I can sometimes start the GUI (but never run through the JUNit Tests).
      So I checked the code and followed the lines...
      Next point i found out was that It was not possible to connect to the Service twice with the same programinstance. If I had disconeccted and tried again to connect to the "ATM-Terminal" I get the same error as follows:

      20060822 17:32:42:495 DEBUG [Link: javax.xml.rpc.soap.SOAPFaultException.<init>(SOAPFaultException.java:91)] - new SOAPFaultException [code={http://schemas.xmlsoap.org/soap/envelope/}Server,string=The service is not in an appropiate state for the requested operation,actor=null,detail=null]
      20060822 17:32:42:511 ERROR [Link: org.jboss.ws.jaxrpc.CallImpl.invokeInternal(CallImpl.java:713)] - Call invocation failed
      javax.xml.rpc.soap.SOAPFaultException: The service is not in an appropiate state for the requested operation
       at org.jboss.ws.jaxrpc.SOAPFaultExceptionHelper.getSOAPFaultException(SOAPFaultExceptionHelper.java:100)
       at org.jboss.ws.binding.soap.SOAPBindingProvider.unbindResponseMessage(SOAPBindingProvider.java:505)
       at org.jboss.ws.jaxrpc.CallImpl.invokeInternal(CallImpl.java:704)
       at org.jboss.ws.jaxrpc.CallImpl.invoke(CallImpl.java:398)
       at org.jboss.ws.jaxrpc.CallProxy.invoke(CallProxy.java:164)
       at $Proxy2.status(Unknown Source)
       at org.jbpm.bpel.tutorial.atm.terminal.ConnectAction.actionPerformed(ConnectAction.java:68)
       at javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:1849)
       at javax.swing.AbstractButton$Handler.actionPerformed(AbstractButton.java:2169)
       at javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:420)
       at javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:258)
       at javax.swing.plaf.basic.BasicButtonListener.mouseReleased(BasicButtonListener.java:234)
       at java.awt.Component.processMouseEvent(Component.java:5488)
       at javax.swing.JComponent.processMouseEvent(JComponent.java:3126)
       at java.awt.Component.processEvent(Component.java:5253)
       at java.awt.Container.processEvent(Container.java:1966)
       at java.awt.Component.dispatchEventImpl(Component.java:3955)
       at java.awt.Container.dispatchEventImpl(Container.java:2024)
       at java.awt.Component.dispatchEvent(Component.java:3803)
       at java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4212)
       at java.awt.LightweightDispatcher.processMouseEvent(Container.java:3892)
       at java.awt.LightweightDispatcher.dispatchEvent(Container.java:3822)
       at java.awt.Container.dispatchEventImpl(Container.java:2010)
       at java.awt.Window.dispatchEventImpl(Window.java:1774)
       at java.awt.Component.dispatchEvent(Component.java:3803)
       at java.awt.EventQueue.dispatchEvent(EventQueue.java:463)
       at java.awt.EventDispatchThread.pumpOneEventForHierarchy(EventDispatchThread.java:242)
       at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:163)
       at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:157)
       at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:149)
       at java.awt.EventDispatchThread.run(EventDispatchThread.java:110)
      java.rmi.RemoteException: Call invocation failed with code [Server] because of: The service is not in an appropiate state for the requested operation; nested exception is:
       javax.xml.rpc.soap.SOAPFaultException: The service is not in an appropiate state for the requested operation
       at org.jboss.ws.jaxrpc.CallImpl.invokeInternal(CallImpl.java:715)
       at org.jboss.ws.jaxrpc.CallImpl.invoke(CallImpl.java:398)
       at org.jboss.ws.jaxrpc.CallProxy.invoke(CallProxy.java:164)
       at $Proxy2.status(Unknown Source)
       at org.jbpm.bpel.tutorial.atm.terminal.ConnectAction.actionPerformed(ConnectAction.java:68)
       at javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:1849)
       at javax.swing.AbstractButton$Handler.actionPerformed(AbstractButton.java:2169)
       at javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:420)
       at javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:258)
       at javax.swing.plaf.basic.BasicButtonListener.mouseReleased(BasicButtonListener.java:234)
       at java.awt.Component.processMouseEvent(Component.java:5488)
       at javax.swing.JComponent.processMouseEvent(JComponent.java:3126)
       at java.awt.Component.processEvent(Component.java:5253)
       at java.awt.Container.processEvent(Container.java:1966)
       at java.awt.Component.dispatchEventImpl(Component.java:3955)
       at java.awt.Container.dispatchEventImpl(Container.java:2024)
       at java.awt.Component.dispatchEvent(Component.java:3803)
       at java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4212)
       at java.awt.LightweightDispatcher.processMouseEvent(Container.java:3892)
       at java.awt.LightweightDispatcher.dispatchEvent(Container.java:3822)
       at java.awt.Container.dispatchEventImpl(Container.java:2010)
       at java.awt.Window.dispatchEventImpl(Window.java:1774)
       at java.awt.Component.dispatchEvent(Component.java:3803)
       at java.awt.EventQueue.dispatchEvent(EventQueue.java:463)
       at java.awt.EventDispatchThread.pumpOneEventForHierarchy(EventDispatchThread.java:242)
       at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:163)
       at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:157)
       at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:149)
       at java.awt.EventDispatchThread.run(EventDispatchThread.java:110)
      Caused by: javax.xml.rpc.soap.SOAPFaultException: The service is not in an appropiate state for the requested operation
       at org.jboss.ws.jaxrpc.SOAPFaultExceptionHelper.getSOAPFaultException(SOAPFaultExceptionHelper.java:100)
       at org.jboss.ws.binding.soap.SOAPBindingProvider.unbindResponseMessage(SOAPBindingProvider.java:505)
       at org.jboss.ws.jaxrpc.CallImpl.invokeInternal(CallImpl.java:704)
       ... 28 more
      


      Now I have found out that there may be a timeoutproblem like at this code here:

      ConnectAction.java
       public void actionPerformed(ActionEvent event) {
       Map context = AtmTerminal.getContext();
       AtmPanel atmPanel = (AtmPanel) context.get(AtmTerminal.PANEL);
      
       InitialContext ctx = null;
       try {
       ctx = getInitialContext();
       // JNDI name of service interface (in application-client.xml)
       String serviceRefName = "service/ATM";
       // lookup service interface in environment context
       AtmFrontEndService service = (AtmFrontEndService) ctx.lookup("java:comp/env/" + serviceRefName);
       // obtain dynamic proxy for web service port
       AtmFrontEnd atmFrontEnd = service.getAtmRelationPort();
       context.put(AtmTerminal.FRONT_END, atmFrontEnd);
      
       // connect to atm service
       int ticketNo = atmFrontEnd.connect();
       context.put(AtmTerminal.TICKET, new Integer(ticketNo));
      
       // update atm panel
       atmPanel.setMessage("Please log on,\nso we can begin");
       atmPanel.clearActions();
       atmPanel.addAction(new LogOnAction());
       atmPanel.addAction(new DisconnectAction());
       atmPanel.setStatus(atmFrontEnd.status(ticketNo).getValue());
       }
       catch (Exception e) {
       atmPanel.setMessage("Sorry, I am experiencing\ntechnical problems.\nPlease use another terminal.");
       e.printStackTrace();
       }
       finally {
       if (ctx != null) {
       try {
       ctx.close();
       }
       catch (NamingException e) {
       e.printStackTrace();
       }
       }
       }
       }
      


      If I add a waitstate - this code works fantastically (in comparision to bevore :-) )
       // obtain dynamic proxy for web service port
       atmFrontEnd = service.getAtmRelationPort();
       context.put(AtmTerminal.FRONT_END, atmFrontEnd);
       Thread.sleep(1000); //************** New Code
      
       // connect to atm service
       int ticketNo = atmFrontEnd.connect();
       context.put(AtmTerminal.TICKET, new Integer(ticketNo));
       Thread.sleep(1000); //************** New Code
      


      But this cannot be the real sollution. I have search the Inet (google) and this forum but I haven't found anything in comparision to this...
      I hope anyone can tell me something about this.
      Maybe some timeout settings in SOAP technologie? I have to say that I dont know anything about SOAP actually... -p)

      By the way: I think the reason why I cannot really run through the JUnit test lays exactly at the same point!

      Greetings

      TNT

        • 1. Re: SOAP Fault Exception - BPEL ATM Example
          kvak_tnt

          Is there no one who knows a sollution for this problem?

          I have found out that I need this sleep at most actions Im calling.
          In most cases it would be enough to use 500ms or maybe 250ms as sleeptime.

          Greetings

          TNT

          • 2. Re: SOAP Fault Exception - BPEL ATM Example
            aguizar

            The mentioned fault gets raised when the server takes too much time to process a request. This can be caused by a number of factors:

            no receiver being able to accept the request
            a fault during the execution of the process instance preventing the server from returning a response
            heavy load

            Sleeping at the client side would prevent the server from receiving yet another request when the previous one is not done yet. You'd need to have a very slow machine to outdo the server with just one client, tough.

            I have a Pentium M laptop with a 2 GHz processor and 1 GB of RAM. It is clogged with Windows XP, Outlook, Skype, Trillian and iTunes running in the background. I start JBoss 4.0.4 and run the ant from within Eclipse and still get the test completed in 8 seconds.

            run-test:
             [junit] Testsuite: org.jbpm.bpel.tutorial.atm.ClientTest
             [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 8.859 sec


            Caching at the server makes subsequent runs faster.

            I'd like to see your server log for understanding what is truly going on. Please post it here and send me a copy by email.

            -Alejandro

            • 3. Re: SOAP Fault Exception - BPEL ATM Example
              kvak_tnt

              Hi Alejandro!

              Thanks for your answer! First some explanation of my machine:
              Laptop - Pentium M 1,86 GHz, 2 GB RAM

              Normally my Development Environment runs in a Virtual Machine (768 MB) (it brings me some good options I cant use without a VM).
              As I had this problems I tried the same stuff on a Pentium 4 with 2,83 GHz with 1 GB RAM and got the same effect!

              Some changes I had done in the code:
              I added the jbpm_identity from jbpm to database and changed some code / xmls to get this working. But this should not affect the problem.


              So here ist my Serverlog bevore I start to do anything:

              ===============================================================================
              .
               JBoss Bootstrap Environment
              .
               JBOSS_HOME: C:\Entwicklung\jboss-4.0.4.GA\bin\\..
              .
               JAVA: C:\Programme\Java\jdk1.5.0_06\\bin\java
              .
               JAVA_OPTS: -Dprogram.name=run.bat -Xms128m -Xmx512m -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000
              .
               CLASSPATH: C:\Programme\Java\jdk1.5.0_06\\lib\tools.jar;C:\Entwicklung\jboss-4.0.4.GA\bin\\run.jar
              .
              ===============================================================================
              .
              10:07:21,915 INFO [Server] Starting JBoss (MX MicroKernel)...
              10:07:21,930 INFO [Server] Release ID: JBoss [Zion] 4.0.4.GA (build: CVSTag=JBoss_4_0_4_GA date=200605151000)
              10:07:21,930 INFO [Server] Home Dir: C:\Entwicklung\jboss-4.0.4.GA
              10:07:21,930 INFO [Server] Home URL: file:/C:/Entwicklung/jboss-4.0.4.GA/
              10:07:21,930 INFO [Server] Patch URL: null
              10:07:21,930 INFO [Server] Server Name: default
              10:07:21,930 INFO [Server] Server Home Dir: C:\Entwicklung\jboss-4.0.4.GA\server\default
              10:07:21,930 INFO [Server] Server Home URL: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/
              10:07:21,930 INFO [Server] Server Log Dir: C:\Entwicklung\jboss-4.0.4.GA\server\default\log
              10:07:21,930 INFO [Server] Server Temp Dir: C:\Entwicklung\jboss-4.0.4.GA\server\default\tmp
              10:07:21,946 INFO [Server] Root Deployment Filename: jboss-service.xml
              10:07:22,274 INFO [ServerInfo] Java version: 1.5.0_06,Sun Microsystems Inc.
              10:07:22,274 INFO [ServerInfo] Java VM: Java HotSpot(TM) Client VM 1.5.0_06-b05,Sun Microsystems Inc.
              10:07:22,274 INFO [ServerInfo] OS-System: Windows XP 5.1,x86
              10:07:22,680 INFO [Server] Core system initialized
              10:07:24,352 INFO [WebService] Using RMI server codebase: http://cw:8083/
              10:07:24,383 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
              10:07:24,618 INFO [NamingService] JNDI bootstrap JNP=/0.0.0.0:1099, RMI=/0.0.0.0:1098, backlog=50, no client SocketFactory, Server SocketFactory=clas
              s org.jboss.net.sockets.DefaultSocketFactory
              10:07:27,258 INFO [Embedded] Catalina naming disabled
              10:07:27,321 INFO [ClusterRuleSetFactory] Unable to find a cluster rule set in the classpath. Will load the default rule set.
              10:07:27,321 INFO [ClusterRuleSetFactory] Unable to find a cluster rule set in the classpath. Will load the default rule set.
              10:07:27,602 INFO [Http11BaseProtocol] Initializing Coyote HTTP/1.1 on http-0.0.0.0-8080
              10:07:27,618 INFO [Catalina] Initialization processed in 297 ms
              10:07:27,618 INFO [StandardService] Starting service jboss.web
              10:07:27,618 INFO [StandardEngine] Starting Servlet Engine: Apache Tomcat/5.5.17
              10:07:27,665 INFO [StandardHost] XML validation disabled
              10:07:27,696 INFO [Catalina] Server startup in 78 ms
              10:07:27,790 INFO [TomcatDeployer] deploy, ctxPath=/invoker, warUrl=.../deploy/http-invoker.sar/invoker.war/
              10:07:28,071 INFO [WebappLoader] Dual registration of jndi stream handler: factory already defined
              10:07:28,649 INFO [TomcatDeployer] deploy, ctxPath=/, warUrl=.../deploy/jbossweb-tomcat55.sar/ROOT.war/
              10:07:29,196 INFO [TomcatDeployer] deploy, ctxPath=/jbossws, warUrl=.../tmp/deploy/tmp34271jbossws-exp.war/
              10:07:29,399 INFO [SubscriptionManager] Bound event dispatcher to java:/EventDispatcher
              10:07:29,930 INFO [TomcatDeployer] deploy, ctxPath=/jbpm-bpel, warUrl=.../tmp/deploy/tmp34272jbpm-bpel.sar-contents/jbpm-bpel-exp.war/
              10:07:30,133 INFO [TomcatDeployer] deploy, ctxPath=/jbossmq-httpil, warUrl=.../deploy/jms/jbossmq-httpil.sar/jbossmq-httpil.war/
              10:07:31,680 INFO [TomcatDeployer] deploy, ctxPath=/web-console, warUrl=.../deploy/management/console-mgr.sar/web-console.war/
              10:07:32,649 INFO [MailService] Mail Service bound to java:/Mail
              10:07:32,805 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-local-jdbc.rar
              10:07:32,837 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-ha-xa-jdbc.rar
              10:07:32,868 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-local-jdbc.rar
              10:07:32,915 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=bpel' to JNDI name 'java:bpel'
              10:07:32,915 INFO [JbpmConfiguration] using jbpm configuration resource 'jbpm.cfg.xml'
              10:07:32,977 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jboss-xa-jdbc.rar
              10:07:33,024 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/jms/jms-ra.rar
              10:07:33,055 INFO [RARDeployment] Required license terms exist, view META-INF/ra.xml in .../deploy/mail-ra.rar
              10:07:33,571 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=DataSourceBinding,name=DefaultDS' to JNDI name 'java:D
              efaultDS'
              10:07:33,821 INFO [A] Bound to JNDI name: queue/A
              10:07:33,821 INFO [B] Bound to JNDI name: queue/B
              10:07:33,821 INFO [C] Bound to JNDI name: queue/C
              10:07:33,837 INFO [D] Bound to JNDI name: queue/D
              10:07:33,837 INFO [ex] Bound to JNDI name: queue/ex
              10:07:33,852 INFO [testTopic] Bound to JNDI name: topic/testTopic
              10:07:33,852 INFO [securedTopic] Bound to JNDI name: topic/securedTopic
              10:07:33,868 INFO [testDurableTopic] Bound to JNDI name: topic/testDurableTopic
              10:07:33,868 INFO [testQueue] Bound to JNDI name: queue/testQueue
              10:07:33,915 INFO [UILServerILService] JBossMQ UIL service available at : /0.0.0.0:8093
              10:07:33,946 INFO [DLQ] Bound to JNDI name: queue/DLQ
              10:07:34,071 INFO [ConnectionFactoryBindingService] Bound ConnectionManager 'jboss.jca:service=ConnectionFactoryBinding,name=JmsXA' to JNDI name 'jav
              a:JmsXA'
              10:07:35,071 INFO [TomcatDeployer] deploy, ctxPath=/account, warUrl=.../tmp/deploy/tmp34302account-exp.war/
              10:07:35,243 INFO [WSDLFilePublisher] WSDL published to: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/data/wsdl/account.war/account.impl.wsdl
              10:07:35,368 INFO [ServiceEndpointManager] WebService started: http://cw:8080/account/accountSystem
              10:07:35,415 INFO [TomcatDeployer] deploy, ctxPath=/jmx-console, warUrl=.../deploy/jmx-console.war/
              10:07:35,712 INFO [TomcatDeployer] deploy, ctxPath=/ticket, warUrl=.../tmp/deploy/tmp34305ticket-exp.war/
              10:07:35,837 INFO [WSDLFilePublisher] WSDL published to: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/data/wsdl/ticket.war/ticket.impl.wsdl
              10:07:35,852 INFO [ServiceEndpointManager] WebService started: http://cw:8080/ticket/ticketIssuer
              10:07:35,868 INFO [EARDeployer] Init J2EE application: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/deploy/atm.ear
              10:07:36,180 INFO [ClientDeployer] Client ENC bound under: atm-client
              10:07:36,196 INFO [TomcatDeployer] deploy, ctxPath=/atm, warUrl=.../tmp/deploy/tmp34306atm.ear-contents/atm-exp.war/
              10:07:36,618 INFO [Environment] Hibernate 3.2 cr2
              10:07:36,618 INFO [Environment] loaded properties from resource hibernate.properties: {hibernate.connection.driver_class=com.mysql.jdbc.Driver, hiber
              nate.dialect=org.hibernate.dialect.MySQLInnoDBDialect, hibernate.query.substitutions=true 1, false 0 , hibernate.connection.username=jbpm_user, hibern
              ate.hbm2ddl.auto=update, hibernate.connection.datasource=java:bpel, hibernate.connection.url=jdbc:mysql://localhost:3306/bpel, hibernate.bytecode.use_
              reflection_optimizer=false, hibernate.show_sql=false, hibernate.connection.password=****}
              10:07:36,633 INFO [Environment] Bytecode provider name : cglib
              10:07:36,649 INFO [Environment] using JDK 1.4 java.sql.Timestamp handling
              10:07:36,821 INFO [Configuration] configuring from resource: hibernate.cfg.xml
              10:07:36,837 INFO [Configuration] Configuration resource: hibernate.cfg.xml
              10:07:36,852 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/action/Script.hbm.xml
              10:07:36,962 INFO [Configuration] Reading mappings from resource: org/jbpm/db/hibernate.queries.hbm.xml
              10:07:36,993 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/def/Transition.hbm.xml
              10:07:37,040 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.Transition -> JBPM_TRANSITION
              10:07:37,633 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/def/Event.hbm.xml
              10:07:37,649 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.Event -> JBPM_EVENT
              10:07:37,665 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/def/Action.hbm.xml
              10:07:37,680 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.Action -> JBPM_ACTION
              10:07:37,696 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/def/SuperState.hbm.xml
              10:07:37,712 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/def/ExceptionHandler.hbm.xml
              10:07:37,743 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.ExceptionHandler -> JBPM_EXCEPTIONHANDLER
              10:07:37,743 INFO [Configuration] Reading mappings from resource: org/jbpm/instantiation/Delegation.hbm.xml
              10:07:37,758 INFO [HbmBinder] Mapping class: org.jbpm.instantiation.Delegation -> JBPM_DELEGATION
              10:07:37,774 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/StartState.hbm.xml
              10:07:37,774 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/EndState.hbm.xml
              10:07:37,790 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/ProcessState.hbm.xml
              10:07:37,805 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/Decision.hbm.xml
              10:07:37,821 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/Fork.hbm.xml
              10:07:37,837 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/Join.hbm.xml
              10:07:37,837 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/State.hbm.xml
              10:07:37,852 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/node/TaskNode.hbm.xml
              10:07:37,868 INFO [Configuration] Reading mappings from resource: org/jbpm/context/def/ContextDefinition.hbm.xml
              10:07:37,868 INFO [Configuration] Reading mappings from resource: org/jbpm/context/def/VariableAccess.hbm.xml
              10:07:37,883 INFO [HbmBinder] Mapping class: org.jbpm.context.def.VariableAccess -> JBPM_VARIABLEACCESS
              10:07:37,899 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/def/TaskMgmtDefinition.hbm.xml
              10:07:37,930 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/def/Swimlane.hbm.xml
              10:07:37,930 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.def.Swimlane -> JBPM_SWIMLANE
              10:07:37,946 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/def/Task.hbm.xml
              10:07:37,962 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.def.Task -> JBPM_TASK
              10:07:37,977 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/def/TaskController.hbm.xml
              10:07:37,993 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.def.TaskController -> JBPM_TASKCONTROLLER
              10:07:37,993 INFO [Configuration] Reading mappings from resource: org/jbpm/module/def/ModuleDefinition.hbm.xml
              10:07:38,008 INFO [HbmBinder] Mapping class: org.jbpm.module.def.ModuleDefinition -> JBPM_MODULEDEFINITION
              10:07:38,024 INFO [Configuration] Reading mappings from resource: org/jbpm/bytes/ByteArray.hbm.xml
              10:07:38,024 INFO [HbmBinder] Mapping class: org.jbpm.bytes.ByteArray -> JBPM_BYTEARRAY
              10:07:38,040 INFO [HbmBinder] Mapping collection: org.jbpm.bytes.ByteArray.byteBlocks -> JBPM_BYTEBLOCK
              10:07:38,040 INFO [Configuration] Reading mappings from resource: org/jbpm/file/def/FileDefinition.hbm.xml
              10:07:38,102 INFO [HbmBinder] Mapping subclass: org.jbpm.file.def.FileDefinition -> JBPM_MODULEDEFINITION
              10:07:38,118 INFO [Configuration] Reading mappings from resource: org/jbpm/scheduler/def/CreateTimerAction.hbm.xml
              10:07:38,118 INFO [HbmBinder] Mapping subclass: org.jbpm.scheduler.def.CreateTimerAction -> JBPM_ACTION
              10:07:38,133 INFO [Configuration] Reading mappings from resource: org/jbpm/scheduler/def/CancelTimerAction.hbm.xml
              10:07:38,149 INFO [HbmBinder] Mapping subclass: org.jbpm.scheduler.def.CancelTimerAction -> JBPM_ACTION
              10:07:38,149 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/exe/Comment.hbm.xml
              10:07:38,165 INFO [HbmBinder] Mapping class: org.jbpm.graph.exe.Comment -> JBPM_COMMENT
              10:07:38,165 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/exe/ProcessInstance.hbm.xml
              10:07:38,180 INFO [HbmBinder] Mapping class: org.jbpm.graph.exe.ProcessInstance -> JBPM_PROCESSINSTANCE
              10:07:38,212 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/exe/Token.hbm.xml
              10:07:38,227 INFO [HbmBinder] Mapping class: org.jbpm.graph.exe.Token -> JBPM_TOKEN
              10:07:38,243 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/exe/RuntimeAction.hbm.xml
              10:07:38,258 INFO [HbmBinder] Mapping class: org.jbpm.graph.exe.RuntimeAction -> JBPM_RUNTIMEACTION
              10:07:38,258 INFO [Configuration] Reading mappings from resource: org/jbpm/module/exe/ModuleInstance.hbm.xml
              10:07:38,274 INFO [HbmBinder] Mapping class: org.jbpm.module.exe.ModuleInstance -> JBPM_MODULEINSTANCE
              10:07:38,274 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/ContextInstance.hbm.xml
              10:07:38,290 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.ContextInstance -> JBPM_MODULEINSTANCE
              10:07:38,290 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/TokenVariableMap.hbm.xml
              10:07:38,305 INFO [HbmBinder] Mapping class: org.jbpm.context.exe.TokenVariableMap -> JBPM_TOKENVARIABLEMAP
              10:07:38,321 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/VariableInstance.hbm.xml
              10:07:38,337 INFO [HbmBinder] Mapping class: org.jbpm.context.exe.VariableInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,352 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/ByteArrayInstance.hbm.xml
              10:07:38,352 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.ByteArrayInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,352 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/DateInstance.hbm.xml
              10:07:38,368 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.DateInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,368 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/DoubleInstance.hbm.xml
              10:07:38,383 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.DoubleInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,383 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/HibernateLongInstance.hbm.xml
              10:07:38,399 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.HibernateLongInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,399 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/HibernateStringInstance.hbm.xml
              10:07:38,415 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.HibernateStringInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,415 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/LongInstance.hbm.xml
              10:07:38,430 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.LongInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,430 INFO [Configuration] Reading mappings from resource: org/jbpm/context/exe/variableinstance/StringInstance.hbm.xml
              10:07:38,446 INFO [HbmBinder] Mapping subclass: org.jbpm.context.exe.variableinstance.StringInstance -> JBPM_VARIABLEINSTANCE
              10:07:38,446 INFO [Configuration] Reading mappings from resource: org/jbpm/msg/Message.hbm.xml
              10:07:38,446 INFO [HbmBinder] Mapping class: org.jbpm.msg.Message -> JBPM_MESSAGE
              10:07:38,462 INFO [Configuration] Reading mappings from resource: org/jbpm/msg/db/TextMessage.hbm.xml
              10:07:38,477 INFO [HbmBinder] Mapping subclass: org.jbpm.msg.db.TextMessage -> JBPM_MESSAGE
              10:07:38,477 INFO [Configuration] Reading mappings from resource: org/jbpm/command/ExecuteActionCommand.hbm.xml
              10:07:38,477 INFO [HbmBinder] Mapping subclass: org.jbpm.command.ExecuteActionCommand -> JBPM_MESSAGE
              10:07:38,493 INFO [Configuration] Reading mappings from resource: org/jbpm/command/ExecuteNodeCommand.hbm.xml
              10:07:38,493 INFO [HbmBinder] Mapping subclass: org.jbpm.command.ExecuteNodeCommand -> JBPM_MESSAGE
              10:07:38,508 INFO [Configuration] Reading mappings from resource: org/jbpm/command/SignalCommand.hbm.xml
              10:07:38,508 INFO [HbmBinder] Mapping subclass: org.jbpm.command.SignalCommand -> JBPM_MESSAGE
              10:07:38,524 INFO [Configuration] Reading mappings from resource: org/jbpm/command/TaskInstanceEndCommand.hbm.xml
              10:07:38,524 INFO [HbmBinder] Mapping subclass: org.jbpm.command.TaskInstanceEndCommand -> JBPM_MESSAGE
              10:07:38,540 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/exe/TaskMgmtInstance.hbm.xml
              10:07:38,555 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.exe.TaskMgmtInstance -> JBPM_MODULEINSTANCE
              10:07:38,555 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/exe/TaskInstance.hbm.xml
              10:07:38,571 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.exe.TaskInstance -> JBPM_TASKINSTANCE
              10:07:38,587 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.TaskInstance.pooledActors -> JBPM_TASKACTORPOOL
              10:07:38,587 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/exe/PooledActor.hbm.xml
              10:07:38,602 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.exe.PooledActor -> JBPM_POOLEDACTOR
              10:07:38,618 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.PooledActor.taskInstances -> JBPM_TASKACTORPOOL
              10:07:38,618 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/exe/SwimlaneInstance.hbm.xml
              10:07:38,618 INFO [HbmBinder] Mapping class: org.jbpm.taskmgmt.exe.SwimlaneInstance -> JBPM_SWIMLANEINSTANCE
              10:07:38,633 INFO [Configuration] Reading mappings from resource: org/jbpm/scheduler/exe/Timer.hbm.xml
              10:07:38,649 INFO [HbmBinder] Mapping class: org.jbpm.scheduler.exe.Timer -> JBPM_TIMER
              10:07:38,649 INFO [Configuration] Reading mappings from resource: org/jbpm/logging/log/ProcessLog.hbm.xml
              10:07:38,680 INFO [HbmBinder] Mapping class: org.jbpm.logging.log.ProcessLog -> JBPM_LOG
              10:07:38,680 INFO [Configuration] Reading mappings from resource: org/jbpm/logging/log/MessageLog.hbm.xml
              10:07:38,696 INFO [HbmBinder] Mapping subclass: org.jbpm.logging.log.MessageLog -> JBPM_LOG
              10:07:38,696 INFO [Configuration] Reading mappings from resource: org/jbpm/logging/log/CompositeLog.hbm.xml
              10:07:38,712 INFO [HbmBinder] Mapping subclass: org.jbpm.logging.log.CompositeLog -> JBPM_LOG
              10:07:38,712 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/ActionLog.hbm.xml
              10:07:38,712 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.ActionLog -> JBPM_LOG
              10:07:38,712 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/NodeLog.hbm.xml
              10:07:38,727 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.NodeLog -> JBPM_LOG
              10:07:38,727 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/ProcessInstanceCreateLog.hbm.xml
              10:07:38,743 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.ProcessInstanceCreateLog -> JBPM_LOG
              10:07:38,743 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/ProcessInstanceEndLog.hbm.xml
              10:07:38,758 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.ProcessInstanceEndLog -> JBPM_LOG
              10:07:38,758 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/SignalLog.hbm.xml
              10:07:38,774 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.SignalLog -> JBPM_LOG
              10:07:38,774 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/TokenCreateLog.hbm.xml
              10:07:38,774 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.TokenCreateLog -> JBPM_LOG
              10:07:38,790 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/TokenEndLog.hbm.xml
              10:07:38,790 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.TokenEndLog -> JBPM_LOG
              10:07:38,790 INFO [Configuration] Reading mappings from resource: org/jbpm/graph/log/TransitionLog.hbm.xml
              10:07:38,805 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.log.TransitionLog -> JBPM_LOG
              10:07:38,805 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/VariableLog.hbm.xml
              10:07:38,821 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.VariableLog -> JBPM_LOG
              10:07:38,821 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/VariableCreateLog.hbm.xml
              10:07:38,837 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.VariableCreateLog -> JBPM_LOG
              10:07:38,837 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/VariableDeleteLog.hbm.xml
              10:07:38,837 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.VariableDeleteLog -> JBPM_LOG
              10:07:38,852 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/VariableUpdateLog.hbm.xml
              10:07:38,868 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.VariableUpdateLog -> JBPM_LOG
              10:07:38,868 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/ByteArrayUpdateLog.hbm.xml
              10:07:38,868 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.ByteArrayUpdateLog -> JBPM_LOG
              10:07:38,868 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/DateUpdateLog.hbm.xml
              10:07:38,883 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.DateUpdateLog -> JBPM_LOG
              10:07:38,883 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/DoubleUpdateLog.hbm.xml
              10:07:38,899 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.DoubleUpdateLog -> JBPM_LOG
              10:07:38,899 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/HibernateLongUpdateLog.hbm.xml
              10:07:38,915 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.HibernateLongUpdateLog -> JBPM_LOG
              10:07:38,915 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/HibernateStringUpdateLog.hbm.xml
              10:07:38,915 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.HibernateStringUpdateLog -> JBPM_LOG
              10:07:38,915 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/LongUpdateLog.hbm.xml
              10:07:38,930 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.LongUpdateLog -> JBPM_LOG
              10:07:38,930 INFO [Configuration] Reading mappings from resource: org/jbpm/context/log/variableinstance/StringUpdateLog.hbm.xml
              10:07:38,946 INFO [HbmBinder] Mapping subclass: org.jbpm.context.log.variableinstance.StringUpdateLog -> JBPM_LOG
              10:07:38,946 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/TaskLog.hbm.xml
              10:07:38,962 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.TaskLog -> JBPM_LOG
              10:07:38,962 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/TaskCreateLog.hbm.xml
              10:07:38,962 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.TaskCreateLog -> JBPM_LOG
              10:07:38,962 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/TaskAssignLog.hbm.xml
              10:07:38,977 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.TaskAssignLog -> JBPM_LOG
              10:07:38,977 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/TaskEndLog.hbm.xml
              10:07:39,008 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.TaskEndLog -> JBPM_LOG
              10:07:39,008 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/SwimlaneLog.hbm.xml
              10:07:39,024 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.SwimlaneLog -> JBPM_LOG
              10:07:39,024 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/SwimlaneCreateLog.hbm.xml
              10:07:39,024 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.SwimlaneCreateLog -> JBPM_LOG
              10:07:39,040 INFO [Configuration] Reading mappings from resource: org/jbpm/taskmgmt/log/SwimlaneAssignLog.hbm.xml
              10:07:39,040 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.log.SwimlaneAssignLog -> JBPM_LOG
              10:07:39,055 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/BpelDefinition.hbm.xml
              10:07:39,055 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.ProcessDefinition -> JBPM_PROCESSDEFINITION
              10:07:39,071 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.BpelDefinition -> JBPM_PROCESSDEFINITION
              10:07:39,087 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/ImportsDefinition.hbm.xml
              10:07:39,102 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.ImportsDefinition -> JBPM_MODULEDEFINITION
              10:07:39,102 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.Import -> BPEL_IMPORT
              10:07:39,118 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/LinkDefinition.hbm.xml
              10:07:39,133 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.LinkDefinition -> BPEL_LINKDEFINITION
              10:07:39,149 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/Activity.hbm.xml
              10:07:39,165 INFO [HbmBinder] Mapping class: org.jbpm.graph.def.Node -> JBPM_NODE
              10:07:39,165 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Activity -> JBPM_NODE
              10:07:39,180 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.CompositeActivity -> JBPM_NODE
              10:07:39,180 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Receive -> JBPM_NODE
              10:07:39,180 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Reply -> JBPM_NODE
              10:07:39,196 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Invoke -> JBPM_NODE
              10:07:39,196 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Throw -> JBPM_NODE
              10:07:39,196 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Exit -> JBPM_NODE
              10:07:39,196 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Wait -> JBPM_NODE
              10:07:39,212 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Empty -> JBPM_NODE
              10:07:39,212 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Compensate -> JBPM_NODE
              10:07:39,227 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Rethrow -> JBPM_NODE
              10:07:39,227 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Validate -> JBPM_NODE
              10:07:39,227 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Assign -> JBPM_NODE
              10:07:39,227 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/StructuredActivity.hbm.xml
              10:07:39,227 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.StructuredActivity -> JBPM_NODE
              10:07:39,243 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Sequence -> JBPM_NODE
              10:07:39,258 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Flow -> JBPM_NODE
              10:07:39,258 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.If -> JBPM_NODE
              10:07:39,258 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Pick -> JBPM_NODE
              10:07:39,258 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.While -> JBPM_NODE
              10:07:39,274 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.While$LoopNode -> JBPM_NODE
              10:07:39,274 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.StructuredActivity$Begin -> JBPM_NODE
              10:07:39,274 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.StructuredActivity$End -> JBPM_NODE
              10:07:39,274 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/Scope.hbm.xml
              10:07:39,290 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Scope -> JBPM_NODE
              10:07:39,305 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.BpelDefinition$GlobalScope -> JBPM_NODE
              10:07:39,305 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/ScopeHandler.hbm.xml
              10:07:39,321 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.ScopeHandler -> JBPM_NODE
              10:07:39,321 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.Catch -> JBPM_NODE
              10:07:39,321 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.OnEvent -> JBPM_NODE
              10:07:39,337 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.OnAlarm -> JBPM_NODE
              10:07:39,337 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/Namespace.hbm.xml
              10:07:39,352 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.Namespace -> BPEL_NAMESPACE
              10:07:39,352 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/assign/Copy.hbm.xml
              10:07:39,352 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.Assign$Copy -> BPEL_COPY
              10:07:39,368 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/assign/From.hbm.xml
              10:07:39,383 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.Assign$From -> BPEL_FROM
              10:07:39,383 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromVariable -> BPEL_FROM
              10:07:39,383 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromProperty -> BPEL_FROM
              10:07:39,383 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromPartnerLink -> BPEL_FROM
              10:07:39,399 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromExpression -> BPEL_FROM
              10:07:39,415 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromElement -> BPEL_FROM
              10:07:39,415 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.FromText -> BPEL_FROM
              10:07:39,415 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/def/assign/To.hbm.xml
              10:07:39,430 INFO [HbmBinder] Mapping class: org.jbpm.bpel.def.Assign$To -> BPEL_TO
              10:07:39,430 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.ToVariable -> BPEL_TO
              10:07:39,430 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.ToProperty -> BPEL_TO
              10:07:39,446 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.ToPartnerLink -> BPEL_TO
              10:07:39,446 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.def.assign.ToQuery -> BPEL_TO
              10:07:39,446 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/exe/LinkInstance.hbm.xml
              10:07:39,462 INFO [HbmBinder] Mapping class: org.jbpm.bpel.exe.LinkInstance -> BPEL_LINKINSTANCE
              10:07:39,462 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/exe/ScopeInstance.hbm.xml
              10:07:39,477 INFO [HbmBinder] Mapping class: org.jbpm.bpel.exe.ScopeInstance -> BPEL_SCOPEINSTANCE
              10:07:39,493 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.exe.EventInstance -> BPEL_SCOPEINSTANCE
              10:07:39,493 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/exe/FaultValue.hbm.xml
              10:07:39,493 INFO [HbmBinder] Mapping class: org.jbpm.bpel.exe.FaultValue -> BPEL_FAULT
              10:07:39,508 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/data/def/VariableDefinition.hbm.xml
              10:07:39,508 INFO [HbmBinder] Mapping class: org.jbpm.bpel.data.def.VariableDefinition -> BPEL_VARIABLEDEFINITION
              10:07:39,524 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/data/def/VariableType.hbm.xml
              10:07:39,524 INFO [HbmBinder] Mapping class: org.jbpm.bpel.data.def.VariableType -> BPEL_VARIABLETYPE
              10:07:39,555 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.data.def.MessageType -> BPEL_VARIABLETYPE
              10:07:39,555 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.data.def.XmlType -> BPEL_VARIABLETYPE
              10:07:39,555 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.data.def.SchemaType -> BPEL_VARIABLETYPE
              10:07:39,555 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.data.def.ElementType -> BPEL_VARIABLETYPE
              10:07:39,555 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/data/def/ScriptDefinition.hbm.xml
              10:07:39,571 INFO [HbmBinder] Mapping class: org.jbpm.bpel.data.def.ScriptDefinition -> BPEL_SCRIPTDEFINITION
              10:07:39,587 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.data.def.ScriptDefinition.namespaces -> BPEL_SCRIPT_NAMESPACE
              10:07:39,587 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/data/exe/ElementInstance.hbm.xml
              10:07:39,587 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.data.exe.ElementInstance -> JBPM_VARIABLEINSTANCE
              10:07:39,602 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/data/exe/MessageValue.hbm.xml
              10:07:39,602 INFO [HbmBinder] Mapping class: org.jbpm.bpel.data.exe.MessageValue -> BPEL_MESSAGEVALUE
              10:07:39,602 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.data.exe.MessageValue.parts -> BPEL_MSGVALUE_PART
              10:07:39,618 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/alarm/def/AlarmDefinition.hbm.xml
              10:07:39,618 INFO [HbmBinder] Mapping class: org.jbpm.bpel.alarm.def.AlarmDefinition -> BPEL_ALARMDEFINITION
              10:07:39,633 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/alarm/exe/AlarmInstance.hbm.xml
              10:07:39,633 INFO [HbmBinder] Mapping class: org.jbpm.bpel.alarm.exe.AlarmInstance -> BPEL_ALARMINSTANCE
              10:07:39,649 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/CorrelationSetDefinition.hbm.xml
              10:07:39,665 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.CorrelationSetDefinition -> BPEL_CORRELATIONSETDEFINITION
              10:07:39,665 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/PartnerLinkDefinition.hbm.xml
              10:07:39,665 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.PartnerLinkDefinition -> BPEL_PARTNERLINKDEFINITION
              10:07:39,680 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/Correlations.hbm.xml
              10:07:39,696 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.Correlations -> BPEL_CORRELATIONS
              10:07:39,696 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.Correlation -> BPEL_CORRELATION
              10:07:39,696 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/Receiver.hbm.xml
              10:07:39,712 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.Receiver -> BPEL_RECEIVER
              10:07:39,712 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/Replier.hbm.xml
              10:07:39,727 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.Replier -> BPEL_REPLIER
              10:07:39,727 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/def/Invoker.hbm.xml
              10:07:39,743 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.def.Invoker -> BPEL_INVOKER
              10:07:39,758 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/exe/CorrelationSetInstance.hbm.xml
              10:07:39,758 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.exe.CorrelationSetInstance -> BPEL_CORRELATIONSETINSTANCE
              10:07:39,758 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.service.exe.CorrelationSetInstance.properties -> BPEL_CORRELATIONSET_PROPERTY
              10:07:39,758 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/exe/PartnerLinkInstance.hbm.xml
              10:07:39,790 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.exe.PartnerLinkInstance -> BPEL_PARTNERLINKINSTANCE
              10:07:39,790 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/exe/EndpointReference.hbm.xml
              10:07:39,805 INFO [HbmBinder] Mapping class: org.jbpm.bpel.service.exe.EndpointReference -> BPEL_ENDPOINTREFERENCE
              10:07:39,805 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/service/exe/SoapEndpointReference.hbm.xml
              10:07:39,821 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.service.exe.SoapEndpointReference -> BPEL_ENDPOINTREFERENCE
              10:07:39,821 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.service.exe.wsa.WsaEndpointReference -> BPEL_ENDPOINTREFERENCE
              10:07:39,821 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.service.exe.wsdl.WsdlEndpointReference -> BPEL_ENDPOINTREFERENCE
              10:07:39,821 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/PropertyImpl.hbm.xml
              10:07:39,837 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PropertyImpl -> BPEL_PROPERTY
              10:07:39,837 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/PartnerLinkTypeImpl.hbm.xml
              10:07:39,852 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PartnerLinkTypeImpl -> BPEL_PARTNERLINKTYPE
              10:07:39,852 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PartnerLinkTypeImpl$RoleImpl -> BPEL_ROLE
              10:07:39,868 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/PropertyAliasImpl.hbm.xml
              10:07:39,868 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PropertyAliasImpl -> BPEL_PROPERTYALIAS
              10:07:39,883 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/OperationImpl.hbm.xml
              10:07:39,899 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.OperationImpl -> WSDL_OPERATION
              10:07:39,899 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/PortTypeImpl.hbm.xml
              10:07:39,899 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PortTypeImpl -> WSDL_PORTTYPE
              10:07:39,915 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/OperationMember.hbm.xml
              10:07:39,915 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.OperationMember -> WSDL_OPERATIONMEMBER
              10:07:39,930 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.wsdl.impl.InputImpl -> WSDL_OPERATIONMEMBER
              10:07:39,930 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.wsdl.impl.OutputImpl -> WSDL_OPERATIONMEMBER
              10:07:39,930 INFO [HbmBinder] Mapping subclass: org.jbpm.bpel.wsdl.impl.FaultImpl -> WSDL_OPERATIONMEMBER
              10:07:39,930 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/MessageImpl.hbm.xml
              10:07:39,946 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.MessageImpl -> WSDL_MESSAGE
              10:07:39,946 INFO [Configuration] Reading mappings from resource: org/jbpm/bpel/wsdl/impl/PartImpl.hbm.xml
              10:07:39,962 INFO [HbmBinder] Mapping class: org.jbpm.bpel.wsdl.impl.PartImpl -> WSDL_PART
              10:07:39,962 INFO [Configuration] Configured SessionFactory: null
              10:07:39,962 INFO [HbmBinder] Mapping subclass: org.jbpm.context.def.ContextDefinition -> JBPM_MODULEDEFINITION
              10:07:39,962 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.ProcessState -> JBPM_NODE
              10:07:39,962 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.State -> JBPM_NODE
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.Join -> JBPM_NODE
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.EndState -> JBPM_NODE
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.StartState -> JBPM_NODE
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.taskmgmt.def.TaskMgmtDefinition -> JBPM_MODULEDEFINITION
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.TaskNode -> JBPM_NODE
              10:07:39,977 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.action.Script -> JBPM_ACTION
              10:07:39,993 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.Fork -> JBPM_NODE
              10:07:39,993 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.node.Decision -> JBPM_NODE
              10:07:39,993 INFO [HbmBinder] Mapping collection: org.jbpm.graph.node.Decision.decisionConditions -> JBPM_DECISIONCONDITIONS
              10:07:39,993 INFO [HbmBinder] Mapping subclass: org.jbpm.graph.def.SuperState -> JBPM_NODE
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Transition.events -> JBPM_EVENT
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Transition.exceptionHandlers -> JBPM_EXCEPTIONHANDLER
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Event.actions -> JBPM_ACTION
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ExceptionHandler.actions -> JBPM_ACTION
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.Swimlane.tasks -> JBPM_TASK
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.Task.events -> JBPM_EVENT
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.Task.exceptionHandlers -> JBPM_EXCEPTIONHANDLER
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.TaskController.variableAccesses -> JBPM_VARIABLEACCESS
              10:07:40,008 INFO [HbmBinder] Mapping collection: org.jbpm.file.def.FileDefinition.processFiles -> JBPM_BYTEARRAY
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.graph.exe.ProcessInstance.runtimeActions -> JBPM_RUNTIMEACTION
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.graph.exe.ProcessInstance.instances -> JBPM_MODULEINSTANCE
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.graph.exe.Token.children -> JBPM_TOKEN
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.graph.exe.Token.comments -> JBPM_COMMENT
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.context.exe.ContextInstance.tokenVariableMaps -> JBPM_TOKENVARIABLEMAP
              10:07:40,024 INFO [HbmBinder] Mapping collection: org.jbpm.context.exe.TokenVariableMap.variableInstances -> JBPM_VARIABLEINSTANCE
              10:07:40,743 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.TaskMgmtInstance.swimlaneInstances -> JBPM_SWIMLANEINSTANCE
              10:07:40,743 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.TaskMgmtInstance.taskInstances -> JBPM_TASKINSTANCE
              10:07:40,743 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.TaskInstance.variableInstances -> JBPM_VARIABLEINSTANCE
              10:07:40,743 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.TaskInstance.comments -> JBPM_COMMENT
              10:07:40,743 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.exe.SwimlaneInstance.pooledActors -> JBPM_POOLEDACTOR
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.logging.log.CompositeLog.children -> JBPM_LOG
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ProcessDefinition.events -> JBPM_EVENT
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ProcessDefinition.exceptionHandlers -> JBPM_EXCEPTIONHANDLER
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ProcessDefinition.nodes -> JBPM_NODE
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ProcessDefinition.actions -> JBPM_ACTION
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.ProcessDefinition.definitions -> JBPM_MODULEDEFINITION
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.BpelDefinition.namespaces -> BPEL_NAMESPACE
              10:07:40,758 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.imports -> BPEL_IMPORT
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.properties -> BPEL_PROPERTY
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.messages -> WSDL_MESSAGE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.partnerLinkTypes -> BPEL_PARTNERLINKTYPE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.portTypes -> WSDL_PORTTYPE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.elementTypes -> BPEL_VARIABLETYPE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.schemaTypes -> BPEL_VARIABLETYPE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.ImportsDefinition.messageTypes -> BPEL_VARIABLETYPE
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Node.events -> JBPM_EVENT
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Node.exceptionHandlers -> JBPM_EXCEPTIONHANDLER
              10:07:40,774 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Node.leavingTransitions -> JBPM_TRANSITION
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.Node.arrivingTransitions -> JBPM_TRANSITION
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Activity.sources -> BPEL_LINKDEFINITION
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Activity.targets -> BPEL_LINKDEFINITION
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Assign.copies -> BPEL_COPY
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.StructuredActivity.nodes -> JBPM_NODE
              10:07:40,790 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Flow.links -> BPEL_LINKDEFINITION
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.If.conditions -> BPEL_SCRIPTDEFINITION
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Pick.onMessages -> BPEL_RECEIVER
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Pick.onAlarms -> BPEL_ALARMDEFINITION
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.handlers -> JBPM_NODE
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.faultHandlers -> JBPM_NODE
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.onEvents -> JBPM_NODE
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.onAlarms -> JBPM_NODE
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.partnerLinks -> BPEL_PARTNERLINKDEFINITION
              10:07:40,805 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.variables -> BPEL_VARIABLEDEFINITION
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.def.Scope.correlationSets -> BPEL_CORRELATIONSETDEFINITION
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.data.def.VariableType.propertyAliases -> BPEL_PROPERTYALIAS
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.service.def.CorrelationSetDefinition.properties -> BPEL_PROPERTY
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.service.def.Correlations.correlations -> BPEL_CORRELATION
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.wsdl.impl.OperationImpl.faults -> WSDL_OPERATIONMEMBER
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.wsdl.impl.PortTypeImpl.operations -> WSDL_OPERATION
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.bpel.wsdl.impl.MessageImpl.parts -> WSDL_PART
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.graph.node.ProcessState.variableAccesses -> JBPM_VARIABLEACCESS
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.TaskMgmtDefinition.swimlanes -> JBPM_SWIMLANE
              10:07:40,821 INFO [HbmBinder] Mapping collection: org.jbpm.taskmgmt.def.TaskMgmtDefinition.tasks -> JBPM_TASK
              10:07:40,837 INFO [HbmBinder] Mapping collection: org.jbpm.graph.node.TaskNode.tasks -> JBPM_TASK
              10:07:40,837 INFO [HbmBinder] Mapping collection: org.jbpm.graph.action.Script.variableAccesses -> JBPM_VARIABLEACCESS
              10:07:40,837 INFO [HbmBinder] Mapping collection: org.jbpm.graph.def.SuperState.nodes -> JBPM_NODE
              10:07:40,993 INFO [NamingHelper] JNDI InitialContext properties:{}
              10:07:40,993 INFO [DatasourceConnectionProvider] Using datasource: java:bpel
              10:07:41,243 INFO [SettingsFactory] RDBMS: MySQL, version: 5.0.24-community-nt
              10:07:41,243 INFO [SettingsFactory] JDBC driver: MySQL-AB JDBC Driver, version: mysql-connector-java-5.0.3 ( $Date: 2006-07-26 17:26:47 +0200 (Wed, 2
              6 Jul 2006) $, $Revision: 5553 $ )
              10:07:41,274 INFO [Dialect] Using dialect: org.hibernate.dialect.MySQLInnoDBDialect
              10:07:41,290 INFO [TransactionFactoryFactory] Using default transaction strategy (direct JDBC transactions)
              10:07:41,290 INFO [TransactionManagerLookupFactory] No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional se
              cond-level cache is not recommended)
              10:07:41,290 INFO [SettingsFactory] Automatic flush during beforeCompletion(): disabled
              10:07:41,290 INFO [SettingsFactory] Automatic session close at end of transaction: disabled
              10:07:41,305 INFO [SettingsFactory] JDBC batch size: 15
              10:07:41,305 INFO [SettingsFactory] JDBC batch updates for versioned data: disabled
              10:07:41,305 INFO [SettingsFactory] Scrollable result sets: enabled
              10:07:41,305 INFO [SettingsFactory] JDBC3 getGeneratedKeys(): enabled
              10:07:41,305 INFO [SettingsFactory] Connection release mode: auto
              10:07:41,305 INFO [SettingsFactory] Maximum outer join fetch depth: 2
              10:07:41,305 INFO [SettingsFactory] Default batch fetch size: 1
              10:07:41,305 INFO [SettingsFactory] Generate SQL with comments: disabled
              10:07:41,305 INFO [SettingsFactory] Order SQL updates by primary key: disabled
              10:07:41,321 INFO [SettingsFactory] Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory
              10:07:41,321 INFO [ASTQueryTranslatorFactory] Using ASTQueryTranslatorFactory
              10:07:41,321 INFO [SettingsFactory] Query language substitutions: {true=1, false=0}
              10:07:41,321 INFO [SettingsFactory] Second-level cache: enabled
              10:07:41,337 INFO [SettingsFactory] Query cache: disabled
              10:07:41,337 INFO [SettingsFactory] Cache provider: org.hibernate.cache.EhCacheProvider
              10:07:41,337 INFO [SettingsFactory] Optimize cache for minimal puts: disabled
              10:07:41,352 INFO [SettingsFactory] Structured second-level cache entries: disabled
              10:07:41,352 INFO [SettingsFactory] Statistics: disabled
              10:07:41,352 INFO [SettingsFactory] Deleted entity synthetic identifier rollback: disabled
              10:07:41,368 INFO [SettingsFactory] Default entity-mode: pojo
              10:07:41,415 INFO [SessionFactoryImpl] building session factory
              10:07:41,821 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.Assign$From]; using defaults.
              10:07:41,868 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PortTypeImpl]; using defaults.
              10:07:42,024 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Node]; using defaults.
              10:07:42,087 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.Replier]; using defaults.
              10:07:42,243 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.Correlation]; using defaults.
              10:07:42,524 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.exe.LinkInstance]; using defaults.
              10:07:42,571 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition]; using defaults.
              10:07:42,649 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ExceptionHandler]; using defaults.
              10:07:42,680 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.OperationImpl]; using defaults.
              10:07:42,712 WARN [EhCacheProvider] Could not find configuration [org.jbpm.module.def.ModuleDefinition]; using defaults.
              10:07:43,290 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.LinkDefinition]; using defaults.
              10:07:43,305 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.exe.EndpointReference]; using defaults.
              10:07:43,462 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.OperationMember]; using defaults.
              10:07:43,508 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PartnerLinkTypeImpl$RoleImpl]; using defaults.
              10:07:43,555 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.data.def.ScriptDefinition]; using defaults.
              10:07:43,727 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Event]; using defaults.
              10:07:43,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.exe.ScopeInstance]; using defaults.
              10:07:43,837 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.Assign$To]; using defaults.
              10:07:43,915 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.alarm.def.AlarmDefinition]; using defaults.
              10:07:43,946 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.Namespace]; using defaults.
              10:07:44,040 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.data.exe.MessageValue]; using defaults.
              10:07:44,071 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PartnerLinkTypeImpl]; using defaults.
              10:07:44,118 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Action]; using defaults.
              10:07:44,149 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Transition]; using defaults.
              10:07:44,274 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.Correlations]; using defaults.
              10:07:44,290 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.Assign$Copy]; using defaults.
              10:07:44,477 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PropertyImpl]; using defaults.
              10:07:44,524 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.TaskController]; using defaults.
              10:07:44,805 WARN [EhCacheProvider] Could not find configuration [org.jbpm.instantiation.Delegation]; using defaults.
              10:07:44,899 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.PartnerLinkDefinition]; using defaults.
              10:07:44,915 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.alarm.exe.AlarmInstance]; using defaults.
              10:07:45,008 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PropertyAliasImpl]; using defaults.
              10:07:45,071 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.Task]; using defaults.
              10:07:45,305 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.PartImpl]; using defaults.
              10:07:45,571 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.exe.PartnerLinkInstance]; using defaults.
              10:07:45,618 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.Invoker]; using defaults.
              10:07:45,805 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.Import]; using defaults.
              10:07:45,852 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.wsdl.impl.MessageImpl]; using defaults.
              10:07:45,883 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.Receiver]; using defaults.
              10:07:45,946 WARN [EhCacheProvider] Could not find configuration [org.jbpm.context.def.VariableAccess]; using defaults.
              10:07:46,133 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.data.def.VariableDefinition]; using defaults.
              10:07:46,196 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.exe.FaultValue]; using defaults.
              10:07:46,571 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.exe.CorrelationSetInstance]; using defaults.
              10:07:46,602 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.service.def.CorrelationSetDefinition]; using defaults.
              10:07:46,680 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.TaskMgmtDefinition.tasks]; using defaults.
              10:07:46,696 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.node.ProcessState.variableAccesses]; using defaults.
              10:07:46,696 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.Swimlane.tasks]; using defaults.
              10:07:46,696 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition.exceptionHandlers]; using defaults.
              10:07:46,696 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Transition.exceptionHandlers]; using defaults.
              10:07:46,712 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition.nodes]; using defaults.
              10:07:46,712 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.node.TaskNode.tasks]; using defaults.
              10:07:46,712 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Node.arrivingTransitions]; using defaults.
              10:07:46,727 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Node.events]; using defaults.
              10:07:46,727 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.action.Script.variableAccesses]; using defaults.
              10:07:46,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition.events]; using defaults.
              10:07:46,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.def.BpelDefinition.namespaces]; using defaults.
              10:07:46,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Node.leavingTransitions]; using defaults.
              10:07:46,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.TaskController.variableAccesses]; using defaults.
              10:07:46,743 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.node.Decision.decisionConditions]; using defaults.
              10:07:46,758 WARN [EhCacheProvider] Could not find configuration [org.jbpm.file.def.FileDefinition.processFiles]; using defaults.
              10:07:46,758 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition.actions]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ProcessDefinition.definitions]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Event.actions]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.bpel.data.def.ScriptDefinition.namespaces]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.Task.events]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.TaskMgmtDefinition.swimlanes]; using defaults.
              10:07:46,774 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.SuperState.nodes]; using defaults.
              10:07:46,790 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.ExceptionHandler.actions]; using defaults.
              10:07:46,790 WARN [EhCacheProvider] Could not find configuration [org.jbpm.taskmgmt.def.Task.exceptionHandlers]; using defaults.
              10:07:46,790 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Node.exceptionHandlers]; using defaults.
              10:07:46,790 WARN [EhCacheProvider] Could not find configuration [org.jbpm.graph.def.Transition.events]; using defaults.
              10:07:48,055 INFO [SessionFactoryObjectFactory] Not binding factory to JNDI, no JNDI name configured
              10:07:48,102 INFO [SchemaUpdate] Running hbm2ddl schema update
              10:07:48,102 INFO [SchemaUpdate] fetching database metadata
              10:07:48,118 INFO [SchemaUpdate] updating schema
              10:07:48,196 INFO [TableMetadata] table found: bpel.bpel_alarmdefinition
              10:07:48,196 INFO [TableMetadata] columns: [listenertype_, alarmlistener_, pickindex_, repeat_, pick_, id_, for_, until_]
              10:07:48,196 INFO [TableMetadata] foreign keys: [fk2dcf5b7a2ba02792, fk_alarmdef_for, fk_alarmdef_repeat, fk_alarmdef_until]
              10:07:48,196 INFO [TableMetadata] indexes: [fk2dcf5b7a2ba02792, fk_alarmdef_for, primary, fk_alarmdef_repeat, fk_alarmdef_until]
              10:07:48,227 INFO [TableMetadata] table found: bpel.bpel_alarminstance
              10:07:48,227 INFO [TableMetadata] columns: [repeat_, token_, duedate_, definition_, id_, handle_]
              10:07:48,227 INFO [TableMetadata] foreign keys: [fk_alarminst_alarmdef, fk_alarminst_token]
              10:07:48,227 INFO [TableMetadata] indexes: [fk_alarminst_alarmdef, primary, fk_alarminst_token]
              10:07:48,258 INFO [TableMetadata] table found: bpel.bpel_copy
              10:07:48,258 INFO [TableMetadata] columns: [assign_, assignindex_, to_, id_, from_]
              10:07:48,258 INFO [TableMetadata] foreign keys: [fk_copy_assign, fk_copy_from, fk_copy_to]
              10:07:48,258 INFO [TableMetadata] indexes: [primary, fk_copy_assign, fk_copy_from, to_, fk_copy_to, from_]
              10:07:48,290 INFO [TableMetadata] table found: bpel.bpel_correlation
              10:07:48,290 INFO [TableMetadata] columns: [csetname_, correlationset_, initiate, correlations_, id]
              10:07:48,290 INFO [TableMetadata] foreign keys: [fkacd03598fabe3aab, fk_csetdef_correlation]
              10:07:48,290 INFO [TableMetadata] indexes: [primary, fkacd03598fabe3aab, fk_csetdef_correlation]
              10:07:48,305 INFO [TableMetadata] table found: bpel.bpel_correlations
              10:07:48,305 INFO [TableMetadata] columns: [id]
              10:07:48,305 INFO [TableMetadata] foreign keys: []
              10:07:48,305 INFO [TableMetadata] indexes: [primary]
              10:07:48,305 INFO [TableMetadata] table found: bpel.bpel_correlationsetdefinition
              10:07:48,305 INFO [TableMetadata] columns: [name_, id_, scope_]
              10:07:48,321 INFO [TableMetadata] foreign keys: [fkce78187d4d5c0a2c]
              10:07:48,321 INFO [TableMetadata] indexes: [primary, fkce78187d4d5c0a2c]
              10:07:48,321 INFO [TableMetadata] table found: bpel.bpel_correlationsetinstance
              10:07:48,321 INFO [TableMetadata] columns: [definition_, id_]
              10:07:48,321 INFO [TableMetadata] foreign keys: [fk_csetinst_csetdef]
              10:07:48,321 INFO [TableMetadata] indexes: [primary, fk_csetinst_csetdef]
              10:07:48,352 INFO [TableMetadata] table found: bpel.bpel_correlationset_property
              10:07:48,352 INFO [TableMetadata] columns: [correlationset_, namespace_, localname_, value_]
              10:07:48,352 INFO [TableMetadata] foreign keys: [fk_property_csetinst]
              10:07:48,352 INFO [TableMetadata] indexes: [fk_property_csetinst, primary]
              10:07:48,368 INFO [TableMetadata] table found: bpel.bpel_endpointreference
              10:07:48,368 INFO [TableMetadata] columns: [porttypelocalname_, scheme_, servicelocalname_, porttypenamespace_, portname_, servicenamespace_, address
              _, class_, id_]
              10:07:48,368 INFO [TableMetadata] foreign keys: []
              10:07:48,368 INFO [TableMetadata] indexes: [primary]
              10:07:48,383 INFO [TableMetadata] table found: bpel.bpel_fault
              10:07:48,383 INFO [TableMetadata] columns: [elementvalue_, namespace_, id_, messagevalue_, localname_]
              10:07:48,383 INFO [TableMetadata] foreign keys: [fk_fltvalue_msgvalue]
              10:07:48,383 INFO [TableMetadata] indexes: [primary, fk_fltvalue_msgvalue]
              10:07:48,399 INFO [TableMetadata] table found: bpel.bpel_from
              10:07:48,415 INFO [TableMetadata] columns: [literal_, part_, endpointref_, partnerlink_, expression_, class_, id_, property_, query_, variable_]
              10:07:48,415 INFO [TableMetadata] foreign keys: [fk_from_expression, fk_from_variable, fk_from_property, fk_from_partnerlink, fk_from_query]
              10:07:48,430 INFO [TableMetadata] indexes: [fk_from_expression, primary, fk_from_property, fk_from_variable, fk_from_partnerlink, fk_from_query]
              10:07:48,462 INFO [TableMetadata] table found: bpel.bpel_import
              10:07:48,462 INFO [TableMetadata] columns: [location_, type_, namespace_, importsindex_, imports_, id]
              10:07:48,462 INFO [TableMetadata] foreign keys: [fka99911afc1a981df]
              10:07:48,477 INFO [TableMetadata] indexes: [primary, fka99911afc1a981df]
              10:07:48,508 INFO [TableMetadata] table found: bpel.bpel_invoker
              10:07:48,508 INFO [TableMetadata] columns: [incorrelations_, outputvariabledefinition_, outcorrelations_, operation_, partnerlinkdefinition_, id, inp
              utvariabledefinition_]
              10:07:48,524 INFO [TableMetadata] foreign keys: [fk_invoker_plinkdef, fk_invoker_outputvardef, fk_invoker_incorrelations, fk_invoker_operation, fk_in
              voker_outcorrelations, fk_invoker_inputvardef]
              10:07:48,540 INFO [TableMetadata] indexes: [fk_invoker_plinkdef, primary, fk_invoker_outputvardef, fk_invoker_incorrelations, fk_invoker_operation, f
              k_invoker_outcorrelations, fk_invoker_inputvardef]
              10:07:48,571 INFO [TableMetadata] table found: bpel.bpel_linkdefinition
              10:07:48,571 INFO [TableMetadata] columns: [flowindex_, condition_, name_, target_, id_, flow, source_]
              10:07:48,587 INFO [TableMetadata] foreign keys: [fk_linkdef_source, fk69cf98d72570256f, fk_linkdef_condition, fk_linkdef_target]
              10:07:48,587 INFO [TableMetadata] indexes: [fk_linkdef_source, primary, fk69cf98d72570256f, fk_linkdef_condition, fk_linkdef_target]
              10:07:48,602 INFO [TableMetadata] table found: bpel.bpel_linkinstance
              10:07:48,618 INFO [TableMetadata] columns: [targettoken_, status_, definition_, id_]
              10:07:48,618 INFO [TableMetadata] foreign keys: [fk_linkinst_linkdef, fk_linkinst_token]
              10:07:48,633 INFO [TableMetadata] indexes: [primary, fk_linkinst_linkdef, fk_linkinst_token]
              10:07:48,649 INFO [TableMetadata] table found: bpel.bpel_messagevalue
              10:07:48,649 INFO [TableMetadata] columns: [type_, id_]
              10:07:48,665 INFO [TableMetadata] foreign keys: [fk_msgvalue_msgtype]
              10:07:48,665 INFO [TableMetadata] indexes: [primary, fk_msgvalue_msgtype]
              10:07:49,337 INFO [TableMetadata] table found: bpel.bpel_msgvalue_part
              10:07:49,337 INFO [TableMetadata] columns: [name_, valu


              • 4. Re: SOAP Fault Exception - BPEL ATM Example
                kvak_tnt

                10:07:49,337 INFO [TableMetadata] columns: [name_, value_, msginstance_]
                10:07:49,352 INFO [TableMetadata] foreign keys: [fk_part_msgvalue]
                10:07:49,352 INFO [TableMetadata] indexes: [primary, fk_part_msgvalue]
                10:07:49,368 INFO [TableMetadata] table found: bpel.bpel_namespace
                10:07:49,383 INFO [TableMetadata] columns: [processdefinition_, uri_, prefix_, id_]
                10:07:49,383 INFO [TableMetadata] foreign keys: [fka2e306f123f8b398]
                10:07:49,383 INFO [TableMetadata] indexes: [primary, fka2e306f123f8b398]
                10:07:49,415 INFO [TableMetadata] table found: bpel.bpel_partnerlinkdefinition
                10:07:49,415 INFO [TableMetadata] columns: [name_, partnerlinktype_, partnerfirst_, id_, scope_]
                10:07:49,415 INFO [TableMetadata] foreign keys: [fkd95d7c2b4d5c0a2c, fk_plinktype_plinkdef]
                10:07:49,430 INFO [TableMetadata] indexes: [primary, fkd95d7c2b4d5c0a2c, fk_plinktype_plinkdef]
                10:07:49,446 INFO [TableMetadata] table found: bpel.bpel_partnerlinkinstance
                10:07:49,446 INFO [TableMetadata] columns: [definition_, id_, partnerreference_]
                10:07:49,462 INFO [TableMetadata] foreign keys: [fk_plinkinst_plinkdef, fk_plinkinst_partnerref]
                10:07:49,462 INFO [TableMetadata] indexes: [primary, fk_plinkinst_plinkdef, fk_plinkinst_partnerref]
                10:07:49,477 INFO [TableMetadata] table found: bpel.bpel_partnerlinktype
                10:07:49,477 INFO [TableMetadata] columns: [firstrole_, namespace_, imports_, secondrole_, localname_, id]
                10:07:49,493 INFO [TableMetadata] foreign keys: [fk_plinktype_firstrole, fk_plinktype_secondrole, fk2344e412c1a981df]
                10:07:49,493 INFO [TableMetadata] indexes: [primary, fk_plinktype_firstrole, fk_plinktype_secondrole, fk2344e412c1a981df]
                10:07:49,508 INFO [TableMetadata] table found: bpel.bpel_property
                10:07:49,524 INFO [TableMetadata] columns: [properties_, namespace_, typelocalname_, imports_, typenamespace_, localname_, id]
                10:07:49,524 INFO [TableMetadata] foreign keys: [fk85961d5fc1a981df, fk85961d5f8b9764ab]
                10:07:49,540 INFO [TableMetadata] indexes: [primary, fk85961d5fc1a981df, fk85961d5f8b9764ab]
                10:07:49,571 INFO [TableMetadata] table found: bpel.bpel_propertyalias
                10:07:49,571 INFO [TableMetadata] columns: [message_, part_, namespace_, typelocalname_, elementlocalname_, query_, property_, variabletype_, element
                namespace_, typenamespace_, localname_, id]
                10:07:49,587 INFO [TableMetadata] foreign keys: [fk_alias_query, fk_alias_message, fk_alias_property, fkaa880431b77cba02]
                10:07:49,587 INFO [TableMetadata] indexes: [primary, fk_alias_query, fk_alias_message, fkaa880431b77cba02, fk_alias_property]
                10:07:49,618 INFO [TableMetadata] table found: bpel.bpel_receiver
                10:07:49,618 INFO [TableMetadata] columns: [listenertype_, pickindex_, operation_, pick_, correlations_, messageexchange, messagelistener_, partnerli
                nkdefinition_, variabledefinition_, id]
                10:07:49,633 INFO [TableMetadata] foreign keys: [fk_receiver_vardef, fk_receiver_correlations, fk_receiver_plinkdef, fk909429792ba02792, fk_receiver_
                operation]
                10:07:49,649 INFO [TableMetadata] indexes: [primary, fk_receiver_vardef, fk_receiver_correlations, fk_receiver_plinkdef, fk909429792ba02792, fk_recei
                ver_operation]
                10:07:49,665 INFO [TableMetadata] table found: bpel.bpel_replier
                10:07:49,680 INFO [TableMetadata] columns: [faultlocalname_, operation_, faultnamespace_, correlations_, partnerlinkdefinition_, variabledefinition_,
                messageexchange_, id]
                10:07:49,680 INFO [TableMetadata] foreign keys: [fk_replier_plinkdef, fk_replier_operation, fk_replier_correlations, fk_replier_vardef]
                10:07:49,696 INFO [TableMetadata] indexes: [primary, fk_replier_plinkdef, fk_replier_operation, fk_replier_correlations, fk_replier_vardef]
                10:07:49,712 INFO [TableMetadata] table found: bpel.bpel_role
                10:07:49,712 INFO [TableMetadata] columns: [name_, porttype_, id]
                10:07:49,727 INFO [TableMetadata] foreign keys: [fk_role_porttype]
                10:07:49,727 INFO [TableMetadata] indexes: [primary, fk_role_porttype]
                10:07:49,743 INFO [TableMetadata] table found: bpel.bpel_scopeinstance
                10:07:49,758 INFO [TableMetadata] columns: [listenertype_, state_, token_, fault_, class_, id_, compensationlistener_]
                10:07:49,758 INFO [TableMetadata] foreign keys: [fk_scopeinst_fault, fk_scopeinst_token]
                10:07:49,758 INFO [TableMetadata] indexes: [primary, fk_scopeinst_fault, fk_scopeinst_token]
                10:07:49,774 INFO [TableMetadata] table found: bpel.bpel_scriptdefinition
                10:07:49,790 INFO [TableMetadata] columns: [text_, use_, switch_, id_, language_, switchindex_]
                10:07:49,790 INFO [TableMetadata] foreign keys: [fk8167c9e81f4f089b]
                10:07:49,805 INFO [TableMetadata] indexes: [primary, fk8167c9e81f4f089b]
                10:07:49,821 INFO [TableMetadata] table found: bpel.bpel_script_namespace
                10:07:49,821 INFO [TableMetadata] columns: [scriptdefinition_, namespace_]
                10:07:49,821 INFO [TableMetadata] foreign keys: [fk38f10851b3647c8c, fk38f1085154e21d82]
                10:07:49,837 INFO [TableMetadata] indexes: [fk38f10851b3647c8c, primary, fk38f1085154e21d82]
                10:07:49,852 INFO [TableMetadata] table found: bpel.bpel_to
                10:07:49,852 INFO [TableMetadata] columns: [part_, partnerlink_, class_, id_, property_, query_, variable_]
                10:07:49,868 INFO [TableMetadata] foreign keys: [fk_to_query, fk_to_variable, fk_to_partnerlink, fk_to_property]
                10:07:49,868 INFO [TableMetadata] indexes: [primary, fk_to_query, fk_to_variable, fk_to_partnerlink, fk_to_property]
                10:07:49,899 INFO [TableMetadata] table found: bpel.bpel_variabledefinition
                10:07:49,899 INFO [TableMetadata] columns: [name_, type_, id_, scope_]
                10:07:49,899 INFO [TableMetadata] foreign keys: [fk2c6de3d94d5c0a2c, fk_variabledef_type]
                10:07:49,915 INFO [TableMetadata] indexes: [primary, fk2c6de3d94d5c0a2c, fk_variabledef_type]
                10:07:49,930 INFO [TableMetadata] table found: bpel.bpel_variabletype
                10:07:49,946 INFO [TableMetadata] columns: [message_, namespace_, imports_, class_, id_, localname_]
                10:07:49,946 INFO [TableMetadata] foreign keys: [fk_messagetype_message, fk85f02640c1a981df]
                10:07:49,962 INFO [TableMetadata] indexes: [primary, fk_messagetype_message, fk85f02640c1a981df]
                10:07:49,977 INFO [TableMetadata] table found: bpel.jbpm_action
                10:07:49,977 INFO [TableMetadata] columns: [event_, repeat_, isasync_, class, id_, exceptionhandlerindex_, exceptionhandler_, referencedaction_, ispr
                opagationallowed_, eventindex_, name_, actiondelegation_, timername_, actionexpression_, processdefinition_, timeraction_, expression_, duedate_, tran
                sitionname_]
                10:07:50,008 INFO [TableMetadata] foreign keys: [fk_action_actndel, fk_action_expthdl, fk_crtetimeract_ta, fk_action_event, fk_action_refact, fk_acti
                on_procdef]
                10:07:50,008 INFO [TableMetadata] indexes: [fk_action_actndel, primary, fk_action_expthdl, fk_crtetimeract_ta, fk_action_event, fk_action_refact, fk_
                action_procdef]
                10:07:50,040 INFO [TableMetadata] table found: bpel.jbpm_bytearray
                10:07:50,055 INFO [TableMetadata] columns: [name_, filedefinition_, id_]
                10:07:50,055 INFO [TableMetadata] foreign keys: [fk_bytearr_fildef]
                10:07:50,055 INFO [TableMetadata] indexes: [primary, fk_bytearr_fildef]
                10:07:50,087 INFO [TableMetadata] table found: bpel.jbpm_byteblock
                10:07:50,087 INFO [TableMetadata] columns: [bytes_, index_, processfile_]
                10:07:50,087 INFO [TableMetadata] foreign keys: [fk_byteblock_file]
                10:07:50,102 INFO [TableMetadata] indexes: [primary, fk_byteblock_file]
                10:07:50,118 INFO [TableMetadata] table found: bpel.jbpm_comment
                10:07:50,133 INFO [TableMetadata] columns: [message_, taskinstance_, time_, token_, actorid_, version_, taskinstanceindex_, id_, tokenindex_]
                10:07:50,133 INFO [TableMetadata] foreign keys: [fk_comment_tsk, fk_comment_token]
                10:07:50,149 INFO [TableMetadata] indexes: [primary, fk_comment_tsk, fk_comment_token]
                10:07:50,165 INFO [TableMetadata] table found: bpel.jbpm_decisionconditions
                10:07:50,165 INFO [TableMetadata] columns: [decision_, expression_, transitionname_, index_]
                10:07:50,180 INFO [TableMetadata] foreign keys: [fk_deccond_dec]
                10:07:50,180 INFO [TableMetadata] indexes: [primary, fk_deccond_dec]
                10:07:50,196 INFO [TableMetadata] table found: bpel.jbpm_delegation
                10:07:50,196 INFO [TableMetadata] columns: [classname_, processdefinition_, configuration_, id_, configtype_]
                10:07:50,212 INFO [TableMetadata] foreign keys: [fk_delegation_prcd]
                10:07:50,227 INFO [TableMetadata] indexes: [primary, fk_delegation_prcd]
                10:07:50,243 INFO [TableMetadata] table found: bpel.jbpm_event
                10:07:50,243 INFO [TableMetadata] columns: [type_, processdefinition_, node_, task_, eventtype_, id_, transition_, graphelement_]
                10:07:50,258 INFO [TableMetadata] foreign keys: [fk_event_task, fk_event_procdef, fk_event_trans, fk_event_node]
                10:07:50,258 INFO [TableMetadata] indexes: [fk_event_task, primary, fk_event_procdef, fk_event_trans, fk_event_node]
                10:07:50,274 INFO [TableMetadata] table found: bpel.jbpm_exceptionhandler
                10:07:50,290 INFO [TableMetadata] columns: [type_, processdefinition_, node_, task_, id_, graphelementindex_, transition_, graphelement_, exceptioncl
                assname_]
                10:07:50,305 INFO [TableMetadata] foreign keys: []
                10:07:50,305 INFO [TableMetadata] indexes: [primary]
                10:07:50,337 INFO [TableMetadata] table found: bpel.jbpm_log
                10:07:50,337 INFO [TableMetadata] columns: [child_, newlongidclass_, token_, oldlongidclass_, taskactorid_, oldlongvalue_, class_, id_, newlongvalue_
                , newstringidvalue_, parent_, node_, olddoublevalue_, newlongidvalue_, date_, newdatevalue_, olddatevalue_, swimlaneinstance_, oldstringvalue_, source
                node_, newstringvalue_, leave_, enter_, oldbytearray_, newbytearray_, oldstringidclass_, exception_, destinationnode_, oldlongidvalue_, duration_, ind
                ex_, message_, taskinstance_, newstringidclass_, newdoublevalue_, variableinstance_, transition_, action_, taskoldactorid_, oldstringidvalue_]
                10:07:50,368 INFO [TableMetadata] foreign keys: [fk_log_destnode, fk_log_transition, fk_log_action, fk_log_varinst, fk_log_parent, fk_log_sourcenode,
                fk_log_newbytes, fk_log_node, fk_log_childtoken, fk_log_oldbytes, fk_log_swiminst, fk_log_taskinst, fk_log_token]
                10:07:50,383 INFO [TableMetadata] indexes: [primary, fk_log_destnode, fk_log_transition, fk_log_action, fk_log_varinst, fk_log_parent, fk_log_sourcen
                ode, fk_log_newbytes, fk_log_node, fk_log_childtoken, fk_log_oldbytes, fk_log_swiminst, fk_log_taskinst, fk_log_token]
                10:07:50,399 INFO [TableMetadata] table found: bpel.jbpm_message
                10:07:50,415 INFO [TableMetadata] columns: [text_, destination_, taskinstance_, token_, node_, exception_, class_, id_, transitionname_, issuspended_
                , action_]
                10:07:50,415 INFO [TableMetadata] foreign keys: [fk_cmd_taskinst, fk_msg_token, fk_cmd_node, fk_cmd_action]
                10:07:50,430 INFO [TableMetadata] indexes: [primary, fk_cmd_taskinst, fk_cmd_action, fk_cmd_node, fk_msg_token]
                10:07:50,446 INFO [TableMetadata] table found: bpel.jbpm_moduledefinition
                10:07:50,446 INFO [TableMetadata] columns: [name_, starttask_, processdefinition_, class_, id_]
                10:07:50,462 INFO [TableMetadata] foreign keys: [fk_tskdef_start, fk_moddef_procdef]
                10:07:50,462 INFO [TableMetadata] indexes: [fk_tskdef_start, primary, fk_moddef_procdef]
                10:07:50,477 INFO [TableMetadata] table found: bpel.jbpm_moduleinstance
                10:07:50,493 INFO [TableMetadata] columns: [name_, processinstance_, taskmgmtdefinition_, class_, id_]
                10:07:50,493 INFO [TableMetadata] foreign keys: [fk_taskmgtinst_tmd, fk_modinst_prcinst]
                10:07:50,493 INFO [TableMetadata] indexes: [fk_modinst_prcinst, fk_taskmgtinst_tmd, primary]
                10:07:50,540 INFO [TableMetadata] table found: bpel.jbpm_node
                10:07:50,540 INFO [TableMetadata] columns: [nodecollectionindex_, createinstance_, while_, faultnamespace_, endtasks_, receiver_, class_, id_, alarm_
                , endstruct_, faultlocalname_, processdefinition_, isolated_, scope, joincondition_, faultvariable_, scope_, decisionexpression_, signal_, suppressjoi
                nfailure_, superstate_, subprocessdefinition_, isasync_, createtasks_, compositeactivity_, decisiondelegation, invoker_, name_, condition_, replier_,
                beginstruct_, handlertype_, implicit_, activity_, action_]
                10:07:50,571 INFO [TableMetadata] foreign keys: [fk_node_action, fk_loop_while, fk_onevent_receiver, fk_reply_replier, fk_node_procdef, fk_decision_d
                eleg, fk_handler_scope, fk_end_struct, fk_procst_sbprcdef, fk_begin_struct, fk_while_condition, fk_handler_alarm, fk_activity_composite, fk_node_super
                state, fk_catch_variable, fk_activity_joincondition, fk_handler_activity, fk_invoke_invoker, fkb48cb2cc89fabbf5, fkb48cb2ccb780a1dc]
                10:07:50,587 INFO [TableMetadata] indexes: [primary, fk_node_action, fk_loop_while, fk_onevent_receiver, while_, fk_reply_replier, fk_node_procdef, f
                k_decision_deleg, fk_handler_scope, endstruct_, fk_end_struct, fk_procst_sbprcdef, fk_begin_struct, fk_while_condition, fk_handler_alarm, fk_activity_
                composite, beginstruct_, fk_node_superstate, fk_catch_variable, fk_activity_joincondition, fk_handler_activity, fk_invoke_invoker, fkb48cb2cc89fabbf5,
                fkb48cb2ccb780a1dc]
                10:07:50,618 INFO [TableMetadata] table found: bpel.jbpm_pooledactor
                10:07:50,618 INFO [TableMetadata] columns: [actorid_, id_, swimlaneinstance_]
                10:07:50,618 INFO [TableMetadata] foreign keys: [fk_pooledactor_sli]
                10:07:50,633 INFO [TableMetadata] indexes: [primary, idx_pldactr_actid, fk_pooledactor_sli]
                10:07:50,665 INFO [TableMetadata] table found: bpel.jbpm_processdefinition
                10:07:50,665 INFO [TableMetadata] columns: [name_, version_, startstate_, targetnamespace_, enablecompensation_, class_, id_, abstract_, isterminatio
                nimplicit_, querylang_, expressionlang_]
                10:07:50,680 INFO [TableMetadata] foreign keys: [fk_procdef_strtsta]
                10:07:50,680 INFO [TableMetadata] indexes: [primary, fk_procdef_strtsta]
                10:07:50,696 INFO [TableMetadata] table found: bpel.jbpm_processinstance
                10:07:50,712 INFO [TableMetadata] columns: [start_, processdefinition_, end_, version_, roottoken_, id_, superprocesstoken_, issuspended_]
                10:07:50,712 INFO [TableMetadata] foreign keys: [fk_procin_sproctkn, fk_procin_procdef, fk_procin_roottkn]
                10:07:50,727 INFO [TableMetadata] indexes: [fk_procin_sproctkn, primary, fk_procin_procdef, fk_procin_roottkn]
                10:07:50,743 INFO [TableMetadata] table found: bpel.jbpm_runtimeaction
                10:07:50,743 INFO [TableMetadata] columns: [type_, version_, processinstance_, eventtype_, processinstanceindex_, id_, action_, graphelement_]
                10:07:50,758 INFO [TableMetadata] foreign keys: [fk_rtactn_procinst, fk_rtactn_action]
                10:07:50,758 INFO [TableMetadata] indexes: [fk_rtactn_procinst, primary, fk_rtactn_action]
                10:07:50,774 INFO [TableMetadata] table found: bpel.jbpm_swimlane
                10:07:50,790 INFO [TableMetadata] columns: [name_, assignmentdelegation_, taskmgmtdefinition_, id_, pooledactorsexpression_, actoridexpression_]
                10:07:50,790 INFO [TableMetadata] foreign keys: [fk_swl_assdel, fk_swl_tskmgmtdef]
                10:07:50,790 INFO [TableMetadata] indexes: [fk_swl_assdel, primary, fk_swl_tskmgmtdef]
                10:07:50,821 INFO [TableMetadata] table found: bpel.jbpm_swimlaneinstance
                10:07:50,821 INFO [TableMetadata] columns: [name_, actorid_, taskmgmtinstance_, swimlane_, id_]
                10:07:50,821 INFO [TableMetadata] foreign keys: [fk_swimlaneinst_sl, fk_swimlaneinst_tm]
                10:07:50,837 INFO [TableMetadata] indexes: [primary, fk_swimlaneinst_sl, fk_swimlaneinst_tm]
                10:07:50,852 INFO [TableMetadata] table found: bpel.jbpm_task
                10:07:50,868 INFO [TableMetadata] columns: [assignmentdelegation_, taskcontroller_, swimlane_, taskmgmtdefinition_, id_, issignalling_, actoridexpres
                sion_, pooledactorsexpression_, name_, isblocking_, processdefinition_, startstate_, duedate_, tasknode_, description_]
                10:07:50,883 INFO [TableMetadata] foreign keys: [fk_task_tasknode, fk_task_startst, fk_task_assdel, fk_task_swimlane, fk_tsk_tskctrl, fk_task_taskmgt
                def, fk_task_procdef]
                10:07:50,883 INFO [TableMetadata] indexes: [primary, fk_task_startst, fk_task_tasknode, fk_task_assdel, fk_task_swimlane, fk_tsk_tskctrl, fk_task_tas
                kmgtdef, fk_task_procdef]
                10:07:50,915 INFO [TableMetadata] table found: bpel.jbpm_taskactorpool
                10:07:50,915 INFO [TableMetadata] columns: [taskinstance_, pooledactor_]
                10:07:50,930 INFO [TableMetadata] foreign keys: [fk_tskactpol_plact, fk_taskactpl_tski]
                10:07:50,930 INFO [TableMetadata] indexes: [primary, fk_tskactpol_plact, fk_taskactpl_tski]
                10:07:50,946 INFO [TableMetadata] table found: bpel.jbpm_taskcontroller
                10:07:50,962 INFO [TableMetadata] columns: [taskcontrollerdelegation_, id_]
                10:07:50,962 INFO [TableMetadata] foreign keys: [fk_tskctrl_deleg]
                10:07:50,962 INFO [TableMetadata] indexes: [fk_tskctrl_deleg, primary]
                10:07:51,008 INFO [TableMetadata] table found: bpel.jbpm_taskinstance
                10:07:51,024 INFO [TableMetadata] columns: [start_, isopen_, token_, actorid_, swimlaninstance_, id_, class_, priority_, create_, issignalling_, name
                _, isblocking_, end_, taskmgmtinstance_, task_, duedate_, description_, iscancelled_, issuspended_]
                10:07:51,024 INFO [TableMetadata] foreign keys: [fk_taskinst_tminst, fk_taskinst_token, fk_taskinst_slinst, fk_taskinst_task]
                10:07:51,040 INFO [TableMetadata] indexes: [primary, fk_taskinst_tminst, fk_taskinst_token, fk_taskinst_slinst, idx_task_actorid, fk_taskinst_task]
                10:07:51,071 INFO [TableMetadata] table found: bpel.jbpm_timer
                10:07:51,071 INFO [TableMetadata] columns: [repeat_, token_, exception_, id_, name_, taskinstance_, graphelementtype_, processinstance_, duedate_, tr
                ansitionname_, issuspended_, action_, graphelement_]
                10:07:51,087 INFO [TableMetadata] foreign keys: [fk_timer_tskinst, fk_timer_action, fk_timer_prinst, fk_timer_token]
                10:07:51,087 INFO [TableMetadata] indexes: [primary, fk_timer_tskinst, fk_timer_action, fk_timer_prinst, fk_timer_token]
                10:07:51,118 INFO [TableMetadata] table found: bpel.jbpm_token
                10:07:51,118 INFO [TableMetadata] columns: [start_, id_, isabletoreactivateparent_, subprocessinstance_, nodeenter_, name_, nextlogindex_, version_,
                end_, parent_, processinstance_, node_, isterminationimplicit_, issuspended_]
                10:07:51,133 INFO [TableMetadata] foreign keys: [fk_token_procinst, fk_token_subpi, fk_token_parent, fk_token_node]
                10:07:51,133 INFO [TableMetadata] indexes: [primary, fk_token_procinst, fk_token_subpi, fk_token_parent, fk_token_node]
                10:07:51,165 INFO [TableMetadata] table found: bpel.jbpm_tokenvariablemap
                10:07:51,165 INFO [TableMetadata] columns: [contextinstance_, token_, id_]
                10:07:51,165 INFO [TableMetadata] foreign keys: [fk_tkvarmap_ctxt, fk_tkvarmap_token]
                10:07:51,180 INFO [TableMetadata] indexes: [primary, fk_tkvarmap_ctxt, fk_tkvarmap_token]
                10:07:51,196 INFO [TableMetadata] table found: bpel.jbpm_transition
                10:07:51,212 INFO [TableMetadata] columns: [name_, processdefinition_, to_, fromindex_, id_, from_]
                10:07:51,212 INFO [TableMetadata] foreign keys: [fk_trans_procdef, fk_transition_to, fk_transition_from]
                10:07:51,212 INFO [TableMetadata] indexes: [primary, fk_trans_procdef, fk_transition_to, fk_transition_from]
                10:07:51,243 INFO [TableMetadata] table found: bpel.jbpm_variableaccess
                10:07:51,243 INFO [TableMetadata] columns: [variablename_, access_, taskcontroller_, processstate_, mappedname_, id_, index_, script_]
                10:07:51,258 INFO [TableMetadata] foreign keys: [fk_varacc_tskctrl, fk_varacc_procst, fk_varacc_script]
                10:07:51,258 INFO [TableMetadata] indexes: [primary, fk_varacc_tskctrl, fk_varacc_procst, fk_varacc_script]
                10:07:51,290 INFO [TableMetadata] table found: bpel.jbpm_variableinstance
                10:07:51,290 INFO [TableMetadata] columns: [stringvalue_, bytearrayvalue_, stringidclass_, elementvalue_, token_, tokenvariablemap_, doublevalue_, id
                _, class_, datevalue_, longvalue_, name_, taskinstance_, converter_, processinstance_, longidclass_]
                10:07:51,305 INFO [TableMetadata] foreign keys: [fk_varinst_tkvarmp, fk_byteinst_array, fk_var_tskinst, fk_varinst_prcinst, fk_varinst_tk]
                10:07:51,305 INFO [TableMetadata] indexes: [fk_varinst_tkvarmp, primary, fk_byteinst_array, fk_var_tskinst, fk_varinst_prcinst, fk_varinst_tk]
                10:07:51,337 INFO [TableMetadata] table found: bpel.wsdl_message
                10:07:51,337 INFO [TableMetadata] columns: [namespace_, imports_, localname_, id]
                10:07:51,352 INFO [TableMetadata] foreign keys: [fkbb9e5b0cc1a981df]
                10:07:51,352 INFO [TableMetadata] indexes: [primary, fkbb9e5b0cc1a981df]
                10:07:51,368 INFO [TableMetadata] table found: bpel.wsdl_operation
                10:07:51,383 INFO [TableMetadata] columns: [name_, input_, operationindex_, porttype_, style_, output_, id]
                10:07:51,383 INFO [TableMetadata] foreign keys: [fk_operation_output, fk_operation_input, fk6637f2ce80f8fed]
                10:07:51,399 INFO [TableMetadata] indexes: [primary, fk_operation_output, fk_operation_input, fk6637f2ce80f8fed]
                10:07:51,415 INFO [TableMetadata] table found: bpel.wsdl_operationmember
                10:07:51,415 INFO [TableMetadata] columns: [message_, name_, operation_, class_, id]
                10:07:51,430 INFO [TableMetadata] foreign keys: [fk466fecc6aabc5e71, fk_opermember_message]
                10:07:51,430 INFO [TableMetadata] indexes: [fk466fecc6aabc5e71, primary, fk_opermember_message]
                10:07:51,462 INFO [TableMetadata] table found: bpel.wsdl_part
                10:07:51,462 INFO [TableMetadata] columns: [message_, name_, typelocalname_, elementlocalname_, typenamespace_, elementnamespace_, id]
                10:07:51,477 INFO [TableMetadata] foreign keys: [fka57b66ee863656f1]
                10:07:51,477 INFO [TableMetadata] indexes: [primary, fka57b66ee863656f1]
                10:07:51,493 INFO [TableMetadata] table found: bpel.wsdl_porttype
                10:07:51,508 INFO [TableMetadata] columns: [namespace_, imports_, localname_, id]
                10:07:51,508 INFO [TableMetadata] foreign keys: [fkff3104b6c1a981df]
                10:07:51,524 INFO [TableMetadata] indexes: [primary, fkff3104b6c1a981df]
                10:07:51,524 INFO [SchemaUpdate] schema update complete
                10:07:51,915 WARN [FromElementType] Using non-qualified column reference [id -> ([ID_])]
                10:07:51,946 WARN [FromElementType] Using non-qualified column reference [isSuspended -> ([ISSUSPENDED_])]
                10:07:51,946 WARN [FromElementType] Using non-qualified column reference [token -> ([TOKEN_])]
                10:07:52,008 WARN [FromElementType] Using non-qualified column reference [isSuspended -> ([ISSUSPENDED_])]
                10:07:52,008 WARN [FromElementType] Using non-qualified column reference [token -> ([TOKEN_])]
                10:07:52,040 WARN [FromElementType] Using non-qualified column reference [isSuspended -> ([ISSUSPENDED_])]
                10:07:52,040 WARN [FromElementType] Using non-qualified column reference [token -> ([TOKEN_])]
                10:07:52,071 WARN [FromElementType] Using non-qualified column reference [isSuspended -> ([ISSUSPENDED_])]
                10:07:52,071 WARN [FromElementType] Using non-qualified column reference [token -> ([TOKEN_])]
                10:07:52,149 WARN [FromElementType] Using non-qualified column reference [processInstance -> ([PROCESSINSTANCE_])]
                10:07:52,196 WARN [FromElementType] Using non-qualified column reference [token -> ([TOKEN_])]
                10:07:53,430 INFO [[/atm]] relationServlet: bpel application started
                10:07:53,540 INFO [WSDLFilePublisher] WSDL published to: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/data/wsdl/atm.ear/atm.war/service.wsdl
                10:07:53,696 INFO [ServiceEndpointManager] WebService started: http://cw:8080/atm/frontEnd
                10:07:53,712 INFO [EARDeployer] Started J2EE application: file:/C:/Entwicklung/jboss-4.0.4.GA/server/default/deploy/atm.ear
                10:07:53,790 INFO [Http11BaseProtocol] Starting Coyote HTTP/1.1 on http-0.0.0.0-8080
                10:07:53,946 INFO [ChannelSocket] JK: ajp13 listening on /0.0.0.0:8009
                10:07:53,962 INFO [JkMain] Jk running ID=0 time=0/47 config=null
                10:07:53,993 INFO [Server] JBoss (MX MicroKernel) [4.0.4.GA (build: CVSTag=JBoss_4_0_4_GA date=200605151000)] Started in 32s:47ms




                Server log after JUnit

                org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#192]
                 at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                 at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                 at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                 at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                 at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                 at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                10:14:48,868 ERROR [RequestListener] could not resume process execution
                org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#213]
                 at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                 at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                 at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                 at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                 at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                 at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                10:15:43,602 ERROR [AbstractFlushingEventListener] Could not synchronize database state with session
                org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.graph.e
                xe.Token#232]
                 at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1680)
                 at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2272)
                 at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2180)
                 at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2450)
                 at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:91)
                 at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
                 at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
                 at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
                 at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:297)
                 at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
                 at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:993)
                 at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:340)
                 at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
                 at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:161)
                 at org.jbpm.svc.Services.close(Services.java:211)
                 at org.jbpm.JbpmContext.close(JbpmContext.java:141)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:122)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                
                This errors appear allways - so I think it is a "normal" failure. Maybe some hints what it really means? What I can do to solve it?
                


                JUnit-Log:
                org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#192]
                 at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                 at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                 at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                 at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                 at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                 at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                10:14:48,868 ERROR [RequestListener] could not resume process execution
                org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#213]
                 at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                 at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                 at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                 at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                 at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                 at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                 at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                 at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                10:15:43,602 ERROR [AbstractFlushingEventListener] Could not synchronize database state with session
                org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.graph.e
                xe.Token#232]
                 at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1680)
                 at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2272)
                 at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2180)
                 at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2450)
                 at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:91)
                 at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
                 at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
                 at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
                 at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:297)
                 at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
                 at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:993)
                 at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:340)
                 at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
                 at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:161)
                 at org.jbpm.svc.Services.close(Services.java:211)
                 at org.jbpm.JbpmContext.close(JbpmContext.java:141)
                 at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:122)
                 at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                 at java.lang.Thread.run(Thread.java:595)
                


                • 5. Re: SOAP Fault Exception - BPEL ATM Example
                  kvak_tnt

                  JUnit-Log:

                  org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#192]
                   at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                   at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                   at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                   at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                   at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                   at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                   at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                   at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                   at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                   at java.lang.Thread.run(Thread.java:595)
                  10:14:48,868 ERROR [RequestListener] could not resume process execution
                  org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#213]
                   at org.hibernate.impl.SessionFactoryImpl$1.handleEntityNotFound(SessionFactoryImpl.java:372)
                   at org.hibernate.proxy.AbstractLazyInitializer.checkTargetState(AbstractLazyInitializer.java:79)
                   at org.hibernate.proxy.AbstractLazyInitializer.initialize(AbstractLazyInitializer.java:68)
                   at org.hibernate.proxy.AbstractLazyInitializer.getImplementation(AbstractLazyInitializer.java:111)
                   at org.hibernate.proxy.pojo.cglib.CGLIBLazyInitializer.intercept(CGLIBLazyInitializer.java:160)
                   at org.jbpm.graph.exe.Token$$EnhancerByCGLIB$$1ac30be4.getProcessInstance(<generated>)
                   at org.jbpm.JbpmContext.addAutoSaveToken(JbpmContext.java:470)
                   at org.jbpm.JbpmContext.loadTokenForUpdate(JbpmContext.java:239)
                   at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:92)
                   at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                   at java.lang.Thread.run(Thread.java:595)
                  10:15:43,602 ERROR [AbstractFlushingEventListener] Could not synchronize database state with session
                  org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect): [org.jbpm.graph.e
                  xe.Token#232]
                   at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:1680)
                   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2272)
                   at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:2180)
                   at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:2450)
                   at org.hibernate.action.EntityUpdateAction.execute(EntityUpdateAction.java:91)
                   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:248)
                   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:232)
                   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
                   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:297)
                   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
                   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:993)
                   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:340)
                   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
                   at org.jbpm.persistence.db.DbPersistenceService.close(DbPersistenceService.java:161)
                   at org.jbpm.svc.Services.close(Services.java:211)
                   at org.jbpm.JbpmContext.close(JbpmContext.java:141)
                   at org.jbpm.bpel.relation.jms.RequestListener.onMessage(RequestListener.java:122)
                   at org.jboss.mq.SpyMessageConsumer.run(SpyMessageConsumer.java:694)
                   at java.lang.Thread.run(Thread.java:595)
                  

                  In my environment none of the tests is functional without a sleep of at least 200ms. My JBOSS 4.0.4GA is running in a DOS-Box.
                  I use Eclipse as developmentenvironment and also tried to start JBOSS inside Eclipse - same effect.


                  Last point: I allways get the failure "[Fatal Error] :-1:-1: Premature end of file." when I disconnect / logoff. Do you know why?

                  So thanks in advance for your help!



                  P.S. Sorry for the bad postings, but the forum cuts of ...

                  • 6. Re: SOAP Fault Exception - BPEL ATM Example
                    aguizar

                    Alright, now I understand what is going on. From the server log:

                    org.hibernate.ObjectNotFoundException: No row with the given identifier exists: [org.jbpm.graph.exe.Token#192]


                    the problem is not your machine being slow. On the contrary, it is way faster than mine :) It is receiving new inbound messages in the < onMessage > branches while the transaction that executed the < pick > has not committed yet! There is already a JIRA issue for this: BPEL-198.

                    The solution is upgrading to BPEL 1.1.Beta2, which will be released this week. Thanks for providing your logs.

                    • 7. Re: SOAP Fault Exception - BPEL ATM Example
                      aguizar

                       

                      I allways get the failure "[Fatal Error] :-1:-1: Premature end of file." when I disconnect / logoff. Do you know why?


                      In SOAP over HTTP, one-way operations result in an empty HTTP response. The Apache Xerces parser used by JBossWS emits that message to System.out when given an empty source, but is otherwise harmless.

                      The related issue is JBWS-826.

                      • 8. Re: SOAP Fault Exception - BPEL ATM Example
                        kvak_tnt

                        Hi again!

                        I have upgraded to beta2 and still got the "Premture end of file error"...
                        But now I get it allways I have successfully started an operation in the wsdl.

                        20:00:15,488 ERROR [STDERR] [Fatal Error] :-1:-1: Premature end of file.


                        Any suggestions - or maybe I have missunderstood your statement above...
                        (I think it is in this way harmless... but I' a little bit careful as It appears now every time...)

                        Greetings
                        Claus

                        • 9. Re: SOAP Fault Exception - BPEL ATM Example
                          aguizar

                          If the tests pass, it is harmless. A future version of JBossWS will fix the problem (JBWS-826).