ode-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Matthieu Riou" <matthieu.r...@gmail.com>
Subject Re: Error using Ode on JBoss with Oracle
Date Mon, 06 Aug 2007 22:12:29 GMT
Hi Fernando,

This looks like a problem between Quartz (the ODE scheduler for 1.0) and the
JBoss transaction manager. Apparently triggers aren't properly persisted.

I'm currently cutting a release candidate for ODE 1.1, please give it a try
once it's published, it should ease some of this pain as we've changed the
scheduler for a simpler alternative.

Cheers,
Matthieu

On 8/6/07, Fernando Lozano <fernando.lozano@cinetconsult.com> wrote:
>
> Hi,
>
> I've loaded the necessary schemas for hibernate on Oracle, but I'm still
> getting some errors when running the HelloWorld2 example. Can anybody
> help?
>
>
>
> Thanks,
>
>
> The error race is:
>
> 2007-08-06 08:40:23,218 INFO  [STDOUT] INFO - GeronimoLog.info(79) |
> Deployment of artifact HelloWorld2 successful:
> [{http://ode/bpel/unit-test}HelloWorld2-1]
>
> 2007-08-06 08:40:30,640 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
> Periodic recovery - second pass <lun, 6 ago 2007 08:40:30>
>
> 2007-08-06 08:40:30,640 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
> AtomicActionRecoveryModule: Second pass
>
> 2007-08-06 08:40:30,640 DEBUG
> [com.arjuna.ats.txoj.logging.txojLoggerI18N]
> [com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] -
> TORecoveryModule - second pass
>
> 2007-08-06 08:40:30,640 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
> [com.arjuna.ats.internal.jta.recovery.info.secondpass] Local
> XARecoveryModule - second pass
>
> 2007-08-06 08:40:46,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:40:46,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:40:46,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:40:46,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:46,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:46,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:46,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:47,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:47,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:47,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:40:47,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:40:47,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186403987000) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:40:47,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186403987000) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:40:47,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:40:47,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:40:47,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@bfc8d0
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:40:47,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404012593) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:12,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404012593) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@e8b5fe
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:12,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Checking for Operation using WSAAction :
>
> 2007-08-06 08:41:15,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Checking for Operation using SOAP message body's first child's local
> name : hello
>
> 2007-08-06 08:41:15,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Found operation org.apache.axis2.description.InOutAxisOperation@1230534
>
> 2007-08-06 08:41:15,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Received request message for helloWorld.hello
>
> 2007-08-06 08:41:15,765 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:15,765 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Routed: svcQname {http://ode/bpel/unit-test.wsdl}HelloService -->
> BpelProcess[{http://ode/bpel/unit-test}HelloWorld2-1]
>
> 2007-08-06 08:41:15,781 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,781 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hibernate_sequence.nextval from dual
>
> 2007-08-06 08:41:15,781 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Rehydrating process {http://ode/bpel/unit-test}HelloWorld2-1
>
> 2007-08-06 08:41:15,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Creating process DAO for {http://ode/bpel/unit-test}HelloWorld2-1
> (guid=hqejbhcnphr2hjanpjgq0e)
>
> 2007-08-06 08:41:15,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select this_.ID as ID0_0_, this_.PROCID as PROCID0_0_,
> this_.deployer as deployer0_0_, this_.deploydate as deploydate0_0_,
> this_.type_name as type5_0_0_, this_.type_ns as type6_0_0_,
> this_.version as version0_0_, this_.ACTIVE_ as ACTIVE8_0_0_, this_.guid
> as guid0_0_, this_.INSERT_TIME as INSERT10_0_0_, this_.MLOCK as
> MLOCK0_0_ from BPEL_PROCESS this_ where this_.PROCID=?
>
> 2007-08-06 08:41:15,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,{http://ode/bpel/unit-test}HelloWorld2-1)
>
> 2007-08-06 08:41:15,937 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,953 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,953 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hibernate_sequence.nextval from dual
>
> 2007-08-06 08:41:15,953 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hibernate_sequence.nextval from dual
>
> 2007-08-06 08:41:15,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,968 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> ODE routed to operation Operation: name=hello
>
> style=REQUEST_RESPONSE,1
>
> Input: name=TestIn
>
> Message: name={http://ode/bpel/unit-test.wsdl}HelloMessage
>
> Part: name=TestPart
>
> typeName={http://www.w3.org/2001/XMLSchema}string
>
> Output: name=TestOut
>
> Message: name={http://ode/bpel/unit-test.wsdl}HelloMessage
>
> Part: name=TestPart
>
> typeName={http://www.w3.org/2001/XMLSchema}string from service
> {http://ode/bpel/unit-test.wsdl}HelloService
>
> 2007-08-06 08:41:15,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hibernate_sequence.nextval from dual
>
> 2007-08-06 08:41:15,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:15,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:15,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hibernate_sequence.nextval from dual
>
> 2007-08-06 08:41:16,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Invoking ODE using MEX {MyRoleMex#101 [Client hqejbhcnphr2hjanpjgq0f]
> calling {http://ode/bpel/unit-test.wsdl}HelloService.hello(...)}
>
> 2007-08-06 08:41:16,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Message content:  <?xml version="1.0" encoding="UTF-8"?>
>
> <message><TestPart xmlns:q0="http://ode/bpel/unit-test.wsdl"
> xmlns:soapenv="http://schemas.xmlsoap.org/soap/envelope/"
> xmlns:xsd="http://www.w3.org/2001/XMLSchema"
> xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">Hello</TestPart></
> message>
>
> 2007-08-06 08:41:16,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Routed: svcQname {http://ode/bpel/unit-test.wsdl}HelloService -->
> BpelProcess[{http://ode/bpel/unit-test}HelloWorld2-1]
>
> 2007-08-06 08:41:16,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> invoke() EPR= null ==>
> BpelProcess[{http://ode/bpel/unit-test}HelloWorld2-1]
>
> 2007-08-06 08:41:16,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT JOB_NAME FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ?
> AND JOB_GROUP = ?
>
> 2007-08-06 08:41:16,015 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:16,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_JOB_DETAILS (JOB_NAME, JOB_GROUP,
> DESCRIPTION, JOB_CLASS_NAME, IS_DURABLE, IS_VOLATILE, IS_STATEFUL,
> REQUESTS_RECOVERY, JOB_DATA)  VALUES(?, ?, ?, ?, ?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (4,org.apache.ode.bpel.scheduler.quartz.JobImpl)
> (9,[B@1dc0d09) (8,true) (6,false) (1,hqejbhcnphr2hjanpjgq0g) (3,null)
> (7,false) (5,false)
>
> 2007-08-06 08:41:16,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME =
> ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_GROUP FROM QRTZ_PAUSED_TRIGGER_GRPS WHERE
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,DEFAULT)
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_GROUP FROM QRTZ_PAUSED_TRIGGER_GRPS WHERE
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,_$_ALL_GROUPS_PAUSED_$_)
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_TRIGGERS (TRIGGER_NAME, TRIGGER_GROUP,
> JOB_NAME, JOB_GROUP, IS_VOLATILE, DESCRIPTION, NEXT_FIRE_TIME,
> PREV_FIRE_TIME, TRIGGER_STATE, TRIGGER_TYPE, START_TIME, END_TIME,
> CALENDAR_NAME, MISFIRE_INSTR, JOB_DATA)  VALUES(?, ?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (15,null) (4,DEFAULT) (8,-1) (11,1186404076015)
> (3,hqejbhcnphr2hjanpjgq0g) (7,1186404076015) (12,0) (2,DEFAULT)
> (13,null) (9,WAITING) (6,null) (1,hqejbhcnphr2hjanpjgq0g.trigger) (14,0)
> (10,SIMPLE) (5,false)
>
> 2007-08-06 08:41:16,078 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_SIMPLE_TRIGGERS (TRIGGER_NAME,
> TRIGGER_GROUP, REPEAT_COUNT, REPEAT_INTERVAL, TIMES_TRIGGERED)
> VALUES(?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,078 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (4,0) (1,hqejbhcnphr2hjanpjgq0g.trigger) (3,0) (5,0)
>
> 2007-08-06 08:41:16,078 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,078 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Commiting ODE MEX {MyRoleMex#101 [Client hqejbhcnphr2hjanpjgq0f] calling
> {http://ode/bpel/unit-test.wsdl}HelloService.hello(...)}
>
> 2007-08-06 08:41:16,078 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Commiting transaction.
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404016093) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404016093) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> TRIGGER_STATE = ? AND NEXT_FIRE_TIME = ?
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> TRIGGER_STATE = ? AND NEXT_FIRE_TIME = ?
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,1186404076015) (1,WAITING)
>
> 2007-08-06 08:41:16,093 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,1186404076015) (1,WAITING)
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> TRIGGER_NAME = ? AND TRIGGER_GROUP = ? AND TRIGGER_STATE = ?
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> TRIGGER_NAME = ? AND TRIGGER_GROUP = ? AND TRIGGER_STATE = ?
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,WAITING) (1,ACQUIRED)
> (3,DEFAULT)
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,WAITING) (1,ACQUIRED)
> (3,DEFAULT)
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,109 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,171 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_SIMPLE_TRIGGERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_SIMPLE_TRIGGERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_LISTENER FROM QRTZ_TRIGGER_LISTENERS WHERE
> TRIGGER_NAME = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_LISTENER FROM QRTZ_TRIGGER_LISTENERS WHERE
> TRIGGER_NAME = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_FIRED_TRIGGERS (ENTRY_ID, TRIGGER_NAME,
> TRIGGER_GROUP, IS_VOLATILE, INSTANCE_NAME, FIRED_TIME, STATE, JOB_NAME,
> JOB_GROUP, IS_STATEFUL, REQUESTS_RECOVERY) VALUES(?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_FIRED_TRIGGERS (ENTRY_ID, TRIGGER_NAME,
> TRIGGER_GROUP, IS_VOLATILE, INSTANCE_NAME, FIRED_TIME, STATE, JOB_NAME,
> JOB_GROUP, IS_STATEFUL, REQUESTS_RECOVERY) VALUES(?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,false) (9,null) (8,null)
> (11,false) (6,1186404076015) (1,hqejbhcnphr2hjanpjgq0d1186404017843)
> (3,DEFAULT) (10,false) (7,ACQUIRED) (5,hqejbhcnphr2hjanpjgq0d)
>
> 2007-08-06 08:41:16,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,false) (9,null) (8,null)
> (11,false) (6,1186404076015) (1,hqejbhcnphr2hjanpjgq0d1186404017843)
> (3,DEFAULT) (10,false) (7,ACQUIRED) (5,hqejbhcnphr2hjanpjgq0d)
>
> 2007-08-06 08:41:16,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@7a9fa7
>
> 2007-08-06 08:41:16,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> triggerFired: Trigger 'DEFAULT.hqejbhcnphr2hjanpjgq0g.trigger':
> triggerClass: 'org.quartz.SimpleTrigger isVolatile: false calendar:
> 'null' misfireInstruction: 0 nextFireTime: Mon Aug 06 08:41:16 VET 2007
>
> 2007-08-06 08:41:16,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:16,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:16,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_STATE FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME
> = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_STATE FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME
> = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:16,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT * FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:16,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:16,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:16,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT JOB_LISTENER FROM QRTZ_JOB_LISTENERS WHERE JOB_NAME
> = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:16,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT JOB_LISTENER FROM QRTZ_JOB_LISTENERS WHERE JOB_NAME
> = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:16,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:16,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:16,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_FIRED_TRIGGERS WHERE ENTRY_ID = ?
>
> 2007-08-06 08:41:16,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_FIRED_TRIGGERS WHERE ENTRY_ID = ?
>
> 2007-08-06 08:41:16,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,hqejbhcnphr2hjanpjgq0d1186404017843)
>
> 2007-08-06 08:41:16,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,hqejbhcnphr2hjanpjgq0d1186404017843)
>
> 2007-08-06 08:41:16,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_FIRED_TRIGGERS (ENTRY_ID, TRIGGER_NAME,
> TRIGGER_GROUP, IS_VOLATILE, INSTANCE_NAME, FIRED_TIME, STATE, JOB_NAME,
> JOB_GROUP, IS_STATEFUL, REQUESTS_RECOVERY) VALUES(?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_FIRED_TRIGGERS (ENTRY_ID, TRIGGER_NAME,
> TRIGGER_GROUP, IS_VOLATILE, INSTANCE_NAME, FIRED_TIME, STATE, JOB_NAME,
> JOB_GROUP, IS_STATEFUL, REQUESTS_RECOVERY) VALUES(?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?)
>
> 2007-08-06 08:41:16,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,false) (9,DEFAULT)
> (8,hqejbhcnphr2hjanpjgq0g) (11,true) (6,1186404076015)
> (1,hqejbhcnphr2hjanpjgq0d1186404017843) (3,DEFAULT) (10,false)
> (7,EXECUTING) (5,hqejbhcnphr2hjanpjgq0d)
>
> 2007-08-06 08:41:16,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,hqejbhcnphr2hjanpjgq0g.trigger) (4,false) (9,DEFAULT)
> (8,hqejbhcnphr2hjanpjgq0g) (11,true) (6,1186404076015)
> (1,hqejbhcnphr2hjanpjgq0d1186404017843) (3,DEFAULT) (10,false)
> (7,EXECUTING) (5,hqejbhcnphr2hjanpjgq0d)
>
> 2007-08-06 08:41:16,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME =
> ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME =
> ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_SIMPLE_TRIGGERS SET REPEAT_COUNT = ?,
> REPEAT_INTERVAL = ?, TIMES_TRIGGERED = ? WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_SIMPLE_TRIGGERS SET REPEAT_COUNT = ?,
> REPEAT_INTERVAL = ?, TIMES_TRIGGERED = ? WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,578 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,0) (4,hqejbhcnphr2hjanpjgq0g.trigger) (1,0) (3,1) (5,DEFAULT)
>
> 2007-08-06 08:41:16,578 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,0) (4,hqejbhcnphr2hjanpjgq0g.trigger) (1,0) (3,1) (5,DEFAULT)
>
> 2007-08-06 08:41:16,578 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET JOB_NAME = ?, JOB_GROUP = ?,
> IS_VOLATILE = ?, DESCRIPTION = ?, NEXT_FIRE_TIME = ?, PREV_FIRE_TIME =
> ?, TRIGGER_STATE = ?, TRIGGER_TYPE = ?, START_TIME = ?, END_TIME = ?,
> CALENDAR_NAME = ?, MISFIRE_INSTR = ? WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET JOB_NAME = ?, JOB_GROUP = ?,
> IS_VOLATILE = ?, DESCRIPTION = ?, NEXT_FIRE_TIME = ?, PREV_FIRE_TIME =
> ?, TRIGGER_STATE = ?, TRIGGER_TYPE = ?, START_TIME = ?, END_TIME = ?,
> CALENDAR_NAME = ?, MISFIRE_INSTR = ? WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (4,null) (8,SIMPLE) (11,null) (3,false) (7,COMPLETE) (12,0)
> (2,DEFAULT) (13,hqejbhcnphr2hjanpjgq0g.trigger) (9,1186404076015)
> (6,1186404076015) (1,hqejbhcnphr2hjanpjgq0g) (14,DEFAULT) (10,0) (5,-1)
>
> 2007-08-06 08:41:16,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (4,null) (8,SIMPLE) (11,null) (3,false) (7,COMPLETE) (12,0)
> (2,DEFAULT) (13,hqejbhcnphr2hjanpjgq0g.trigger) (9,1186404076015)
> (6,1186404076015) (1,hqejbhcnphr2hjanpjgq0g) (14,DEFAULT) (10,0) (5,-1)
>
> 2007-08-06 08:41:16,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGER_LISTENERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGER_LISTENERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:16,625 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,625 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:16,625 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@1bda657
>
> 2007-08-06 08:41:16,640 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,640 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,656 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,656 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,656 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:16,656 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:16,656 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,671 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Calling execute on job DEFAULT.hqejbhcnphr2hjanpjgq0g
>
> 2007-08-06 08:41:16,671 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:16,671 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> >> handleWorkEvent(jobData=org.quartz.JobDataMap@a7d5af)
>
> 2007-08-06 08:41:16,671 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,687 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> InvokeInternal event for mexid 101
>
> 2007-08-06 08:41:16,687 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,687 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,687 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,687 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,703 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hmessageex0_.ID as ID6_1_, hmessageex0_.PORT_TYPE as
> PORT2_6_1_, hmessageex0_.CHANNEL_NAME as CHANNEL3_6_1_,
> hmessageex0_.CLIENTKEY as CLIENTKEY6_1_, hmessageex0_.LDATA_EPR_ID as
> LDATA5_6_1_, hmessageex0_.LDATA_CEPR_ID as LDATA6_6_1_,
> hmessageex0_.REQUEST as REQUEST6_1_, hmessageex0_.RESPONSE as
> RESPONSE6_1_, hmessageex0_.INSERT_DT as INSERT9_6_1_,
> hmessageex0_.OPERATION as OPERATION6_1_, hmessageex0_.STATE as
> STATE6_1_, hmessageex0_.PROCESS as PROCESS6_1_, hmessageex0_.PIID as
> PIID6_1_, hmessageex0_.DIR as DIR6_1_, hmessageex0_.PLINK_MODELID as
> PLINK15_6_1_, hmessageex0_.PATTERN as PATTERN6_1_,
> hmessageex0_.CORR_STATUS as CORR17_6_1_, hmessageex0_.FAULT_TYPE as
> FAULT18_6_1_, hmessageex0_.FAULT_EXPL as FAULT19_6_1_,
> hmessageex0_.CALLEE as CALLEE6_1_, hmessageex0_.PARTNERLINK as
> PARTNER21_6_1_, hmessageex0_.PIPED_ID as PIPED22_6_1_,
> hmessageex0_.INSERT_TIME as INSERT23_6_1_, hmessageex0_.MLOCK as
> MLOCK6_1_, hprocess1_.ID as ID0_0_, hprocess1_.PROCID as PROCID0_0_,
> hprocess1_.deployer as deployer0_0_, hprocess1_.deploydate as
> deploydate0_0_, hprocess1_.type_name as type5_0_0_, hprocess1_.type_ns
> as type6_0_0_, hprocess1_.version as version0_0_, hprocess1_.ACTIVE_ as
> ACTIVE8_0_0_, hprocess1_.guid as guid0_0_, hprocess1_.INSERT_TIME as
> INSERT10_0_0_, hprocess1_.MLOCK as MLOCK0_0_ from BPEL_MESSAGE_EXCHANGE
> hmessageex0_ left outer join BPEL_PROCESS hprocess1_ on
> hmessageex0_.PROCESS=hprocess1_.ID where hmessageex0_.ID=?
>
> 2007-08-06 08:41:16,718 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,734 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,101)
>
> 2007-08-06 08:41:16,734 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:16,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:16,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,750 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404016750) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:16,765 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404016750) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:16,765 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:16,765 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:16,781 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Scheduled job failed; jobDetail=org.quartz.JobDataMap@a7d5af
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Rollbacking transaction.
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@1f78541
>
> 2007-08-06 08:41:16,812 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Calling execute on job DEFAULT.hqejbhcnphr2hjanpjgq0g
>
> 2007-08-06 08:41:16,828 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,828 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> >> handleWorkEvent(jobData=org.quartz.JobDataMap@a7d5af)
>
> 2007-08-06 08:41:16,828 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:16,828 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> InvokeInternal event for mexid 101
>
> 2007-08-06 08:41:16,828 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,843 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,843 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,843 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hmessageex0_.ID as ID6_1_, hmessageex0_.PORT_TYPE as
> PORT2_6_1_, hmessageex0_.CHANNEL_NAME as CHANNEL3_6_1_,
> hmessageex0_.CLIENTKEY as CLIENTKEY6_1_, hmessageex0_.LDATA_EPR_ID as
> LDATA5_6_1_, hmessageex0_.LDATA_CEPR_ID as LDATA6_6_1_,
> hmessageex0_.REQUEST as REQUEST6_1_, hmessageex0_.RESPONSE as
> RESPONSE6_1_, hmessageex0_.INSERT_DT as INSERT9_6_1_,
> hmessageex0_.OPERATION as OPERATION6_1_, hmessageex0_.STATE as
> STATE6_1_, hmessageex0_.PROCESS as PROCESS6_1_, hmessageex0_.PIID as
> PIID6_1_, hmessageex0_.DIR as DIR6_1_, hmessageex0_.PLINK_MODELID as
> PLINK15_6_1_, hmessageex0_.PATTERN as PATTERN6_1_,
> hmessageex0_.CORR_STATUS as CORR17_6_1_, hmessageex0_.FAULT_TYPE as
> FAULT18_6_1_, hmessageex0_.FAULT_EXPL as FAULT19_6_1_,
> hmessageex0_.CALLEE as CALLEE6_1_, hmessageex0_.PARTNERLINK as
> PARTNER21_6_1_, hmessageex0_.PIPED_ID as PIPED22_6_1_,
> hmessageex0_.INSERT_TIME as INSERT23_6_1_, hmessageex0_.MLOCK as
> MLOCK6_1_, hprocess1_.ID as ID0_0_, hprocess1_.PROCID as PROCID0_0_,
> hprocess1_.deployer as deployer0_0_, hprocess1_.deploydate as
> deploydate0_0_, hprocess1_.type_name as type5_0_0_, hprocess1_.type_ns
> as type6_0_0_, hprocess1_.version as version0_0_, hprocess1_.ACTIVE_ as
> ACTIVE8_0_0_, hprocess1_.guid as guid0_0_, hprocess1_.INSERT_TIME as
> INSERT10_0_0_, hprocess1_.MLOCK as MLOCK0_0_ from BPEL_MESSAGE_EXCHANGE
> hmessageex0_ left outer join BPEL_PROCESS hprocess1_ on
> hmessageex0_.PROCESS=hprocess1_.ID where hmessageex0_.ID=?
>
> 2007-08-06 08:41:16,859 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,101)
>
> 2007-08-06 08:41:16,875 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,875 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Scheduled job failed; jobDetail=org.quartz.JobDataMap@a7d5af
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:16,906 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Rollbacking transaction.
>
> 2007-08-06 08:41:16,906 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:16,906 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Calling execute on job DEFAULT.hqejbhcnphr2hjanpjgq0g
>
> 2007-08-06 08:41:16,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> >> handleWorkEvent(jobData=org.quartz.JobDataMap@a7d5af)
>
> 2007-08-06 08:41:16,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> InvokeInternal event for mexid 101
>
> 2007-08-06 08:41:16,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:16,921 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hmessageex0_.ID as ID6_1_, hmessageex0_.PORT_TYPE as
> PORT2_6_1_, hmessageex0_.CHANNEL_NAME as CHANNEL3_6_1_,
> hmessageex0_.CLIENTKEY as CLIENTKEY6_1_, hmessageex0_.LDATA_EPR_ID as
> LDATA5_6_1_, hmessageex0_.LDATA_CEPR_ID as LDATA6_6_1_,
> hmessageex0_.REQUEST as REQUEST6_1_, hmessageex0_.RESPONSE as
> RESPONSE6_1_, hmessageex0_.INSERT_DT as INSERT9_6_1_,
> hmessageex0_.OPERATION as OPERATION6_1_, hmessageex0_.STATE as
> STATE6_1_, hmessageex0_.PROCESS as PROCESS6_1_, hmessageex0_.PIID as
> PIID6_1_, hmessageex0_.DIR as DIR6_1_, hmessageex0_.PLINK_MODELID as
> PLINK15_6_1_, hmessageex0_.PATTERN as PATTERN6_1_,
> hmessageex0_.CORR_STATUS as CORR17_6_1_, hmessageex0_.FAULT_TYPE as
> FAULT18_6_1_, hmessageex0_.FAULT_EXPL as FAULT19_6_1_,
> hmessageex0_.CALLEE as CALLEE6_1_, hmessageex0_.PARTNERLINK as
> PARTNER21_6_1_, hmessageex0_.PIPED_ID as PIPED22_6_1_,
> hmessageex0_.INSERT_TIME as INSERT23_6_1_, hmessageex0_.MLOCK as
> MLOCK6_1_, hprocess1_.ID as ID0_0_, hprocess1_.PROCID as PROCID0_0_,
> hprocess1_.deployer as deployer0_0_, hprocess1_.deploydate as
> deploydate0_0_, hprocess1_.type_name as type5_0_0_, hprocess1_.type_ns
> as type6_0_0_, hprocess1_.version as version0_0_, hprocess1_.ACTIVE_ as
> ACTIVE8_0_0_, hprocess1_.guid as guid0_0_, hprocess1_.INSERT_TIME as
> INSERT10_0_0_, hprocess1_.MLOCK as MLOCK0_0_ from BPEL_MESSAGE_EXCHANGE
> hmessageex0_ left outer join BPEL_PROCESS hprocess1_ on
> hmessageex0_.PROCESS=hprocess1_.ID where hmessageex0_.ID=?
>
> 2007-08-06 08:41:16,953 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,101)
>
> 2007-08-06 08:41:16,953 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:16,953 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Scheduled job failed; jobDetail=org.quartz.JobDataMap@a7d5af
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:16,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Rollbacking transaction.
>
> 2007-08-06 08:41:16,984 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:17,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Calling execute on job DEFAULT.hqejbhcnphr2hjanpjgq0g
>
> 2007-08-06 08:41:17,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> >> handleWorkEvent(jobData=org.quartz.JobDataMap@a7d5af)
>
> 2007-08-06 08:41:17,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> InvokeInternal event for mexid 101
>
> 2007-08-06 08:41:17,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:17,000 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: select hmessageex0_.ID as ID6_1_, hmessageex0_.PORT_TYPE as
> PORT2_6_1_, hmessageex0_.CHANNEL_NAME as CHANNEL3_6_1_,
> hmessageex0_.CLIENTKEY as CLIENTKEY6_1_, hmessageex0_.LDATA_EPR_ID as
> LDATA5_6_1_, hmessageex0_.LDATA_CEPR_ID as LDATA6_6_1_,
> hmessageex0_.REQUEST as REQUEST6_1_, hmessageex0_.RESPONSE as
> RESPONSE6_1_, hmessageex0_.INSERT_DT as INSERT9_6_1_,
> hmessageex0_.OPERATION as OPERATION6_1_, hmessageex0_.STATE as
> STATE6_1_, hmessageex0_.PROCESS as PROCESS6_1_, hmessageex0_.PIID as
> PIID6_1_, hmessageex0_.DIR as DIR6_1_, hmessageex0_.PLINK_MODELID as
> PLINK15_6_1_, hmessageex0_.PATTERN as PATTERN6_1_,
> hmessageex0_.CORR_STATUS as CORR17_6_1_, hmessageex0_.FAULT_TYPE as
> FAULT18_6_1_, hmessageex0_.FAULT_EXPL as FAULT19_6_1_,
> hmessageex0_.CALLEE as CALLEE6_1_, hmessageex0_.PARTNERLINK as
> PARTNER21_6_1_, hmessageex0_.PIPED_ID as PIPED22_6_1_,
> hmessageex0_.INSERT_TIME as INSERT23_6_1_, hmessageex0_.MLOCK as
> MLOCK6_1_, hprocess1_.ID as ID0_0_, hprocess1_.PROCID as PROCID0_0_,
> hprocess1_.deployer as deployer0_0_, hprocess1_.deploydate as
> deploydate0_0_, hprocess1_.type_name as type5_0_0_, hprocess1_.type_ns
> as type6_0_0_, hprocess1_.version as version0_0_, hprocess1_.ACTIVE_ as
> ACTIVE8_0_0_, hprocess1_.guid as guid0_0_, hprocess1_.INSERT_TIME as
> INSERT10_0_0_, hprocess1_.MLOCK as MLOCK0_0_ from BPEL_MESSAGE_EXCHANGE
> hmessageex0_ left outer join BPEL_PROCESS hprocess1_ on
> hmessageex0_.PROCESS=hprocess1_.ID where hmessageex0_.ID=?
>
> 2007-08-06 08:41:17,031 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,101)
>
> 2007-08-06 08:41:17,046 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,046 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Scheduled job failed; jobDetail=org.quartz.JobDataMap@a7d5af
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:17,078 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Job could not be completed after 3: hqejbhcnphr2hjanpjgq0g[3]:
> {type=INVOKE_INTERNAL, __scheduler=ODE,
> pid={http://ode/bpel/unit-test}HelloWorld2-1, mexid=101}
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:17,109 INFO  [STDOUT] ERROR - GeronimoLog.error(108) |
> Rescheduling problematic job for a bit later: hqejbhcnphr2hjanpjgq0g[3]:
> {type=INVOKE_INTERNAL, __scheduler=ODE,
> pid={http://ode/bpel/unit-test}HelloWorld2-1, mexid=101}
>
> java.lang.NullPointerException
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.invokeProcess(BpelProcess.java:13
> 7)
>
>                 at
> org.apache.ode.bpel.engine.BpelProcess.handleWorkEvent(BpelProcess.java:
> 280)
>
>                 at
> org.apache.ode.bpel.engine.BpelEngineImpl.onScheduledJob(BpelEngineImpl.
> java:311)
>
>                 at
> org.apache.ode.bpel.engine.BpelServerImpl.onScheduledJob(BpelServerImpl.
> java:390)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.doExecute(Quart
> zSchedulerImpl.java:351)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.QuartzSchedulerImpl.execute(QuartzS
> chedulerImpl.java:367)
>
>                 at
> org.apache.ode.bpel.scheduler.quartz.JobImpl.execute(JobImpl.java:32)
>
>                 at org.quartz.core.JobRunShell.run(JobRunShell.java:203)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecuto
> r.java:650)
>
>                 at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja
> va:675)
>
>                 at java.lang.Thread.run(Thread.java:595)
>
> 2007-08-06 08:41:17,140 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Starting transaction.
>
> 2007-08-06 08:41:17,140 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Commiting transaction.
>
> 2007-08-06 08:41:17,140 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:17,156 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> triggeredJobComplete: trigger=Trigger
> 'DEFAULT.hqejbhcnphr2hjanpjgq0g.trigger':  triggerClass:
> 'org.quartz.SimpleTrigger isVolatile: false calendar: 'null'
> misfireInstruction: 0 nextFireTime: null,
> jobName=DEFAULT.hqejbhcnphr2hjanpjgq0g, triggerInstCode=3
>
> 2007-08-06 08:41:17,156 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT JOB_NAME FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ?
> AND JOB_GROUP = ?
>
> 2007-08-06 08:41:17,156 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:17,156 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0h)
>
> 2007-08-06 08:41:17,171 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:17,171 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_JOB_DETAILS (JOB_NAME, JOB_GROUP,
> DESCRIPTION, JOB_CLASS_NAME, IS_DURABLE, IS_VOLATILE, IS_STATEFUL,
> REQUESTS_RECOVERY, JOB_DATA)  VALUES(?, ?, ?, ?, ?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:17,171 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:17,171 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (4,org.apache.ode.bpel.scheduler.quartz.JobImpl)
> (9,[B@a06577) (8,true) (6,false) (1,hqejbhcnphr2hjanpjgq0h) (3,null)
> (7,false) (5,false)
>
> 2007-08-06 08:41:17,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: pool-4-thread-1
>
> 2007-08-06 08:41:17,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME =
> ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: pool-4-thread-1
>
> 2007-08-06 08:41:17,187 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0h.trigger)
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: pool-4-thread-1
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: pool-4-thread-1
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_GROUP FROM QRTZ_PAUSED_TRIGGER_GRPS WHERE
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: pool-4-thread-1
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,DEFAULT)
>
> 2007-08-06 08:41:17,203 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: pool-4-thread-1
>
> 2007-08-06 08:41:17,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_STATE, NEXT_FIRE_TIME, JOB_NAME, JOB_GROUP
> FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_GROUP FROM QRTZ_PAUSED_TRIGGER_GRPS WHERE
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_STATE, NEXT_FIRE_TIME, JOB_NAME, JOB_GROUP
> FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,218 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,_$_ALL_GROUPS_PAUSED_$_)
>
> 2007-08-06 08:41:17,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_TRIGGERS (TRIGGER_NAME, TRIGGER_GROUP,
> JOB_NAME, JOB_GROUP, IS_VOLATILE, DESCRIPTION, NEXT_FIRE_TIME,
> PREV_FIRE_TIME, TRIGGER_STATE, TRIGGER_TYPE, START_TIME, END_TIME,
> CALENDAR_NAME, MISFIRE_INSTR, JOB_DATA)  VALUES(?, ?, ?, ?, ?, ?, ?, ?,
> ?, ?, ?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:17,234 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,250 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (15,null) (4,DEFAULT) (8,-1) (11,1186404137140)
> (3,hqejbhcnphr2hjanpjgq0h) (7,1186404137140) (12,0) (2,DEFAULT)
> (13,null) (9,WAITING) (6,null) (1,hqejbhcnphr2hjanpjgq0h.trigger) (14,0)
> (10,SIMPLE) (5,false)
>
> 2007-08-06 08:41:17,250 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT J.JOB_NAME, J.JOB_GROUP, J.IS_DURABLE,
> J.JOB_CLASS_NAME, J.REQUESTS_RECOVERY FROM QRTZ_TRIGGERS T,
> QRTZ_JOB_DETAILS J WHERE T.TRIGGER_NAME = ? AND T.TRIGGER_GROUP = ? AND
> T.JOB_NAME = J.JOB_NAME AND T.JOB_GROUP = J.JOB_GROUP
>
> 2007-08-06 08:41:17,250 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: INSERT INTO QRTZ_SIMPLE_TRIGGERS (TRIGGER_NAME,
> TRIGGER_GROUP, REPEAT_COUNT, REPEAT_INTERVAL, TIMES_TRIGGERED)
> VALUES(?, ?, ?, ?, ?)
>
> 2007-08-06 08:41:17,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT J.JOB_NAME, J.JOB_GROUP, J.IS_DURABLE,
> J.JOB_CLASS_NAME, J.REQUESTS_RECOVERY FROM QRTZ_TRIGGERS T,
> QRTZ_JOB_DETAILS J WHERE T.TRIGGER_NAME = ? AND T.TRIGGER_GROUP = ? AND
> T.JOB_NAME = J.JOB_NAME AND T.JOB_GROUP = J.JOB_GROUP
>
> 2007-08-06 08:41:17,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (4,0) (1,hqejbhcnphr2hjanpjgq0h.trigger) (3,0) (5,0)
>
> 2007-08-06 08:41:17,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,265 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Commiting transaction.
>
> 2007-08-06 08:41:17,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:17,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_SIMPLE_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,281 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:17,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_SIMPLE_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:17,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,296 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_CRON_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_CRON_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,312 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_BLOB_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_BLOB_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,328 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,343 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGER_LISTENERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,343 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGER_LISTENERS WHERE TRIGGER_NAME = ?
> AND TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,343 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,343 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,359 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,359 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_TRIGGERS WHERE TRIGGER_NAME = ? AND
> TRIGGER_GROUP = ?
>
> 2007-08-06 08:41:17,359 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,359 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g.trigger)
>
> 2007-08-06 08:41:17,375 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT COUNT(TRIGGER_NAME) FROM QRTZ_TRIGGERS WHERE
> JOB_NAME = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:17,375 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT COUNT(TRIGGER_NAME) FROM QRTZ_TRIGGERS WHERE
> JOB_NAME = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:17,375 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,375 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,390 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> JOB_NAME = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:17,390 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> JOB_NAME = ? AND JOB_GROUP = ?
>
> 2007-08-06 08:41:17,390 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,406 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,406 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_JOB_LISTENERS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:17,406 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_JOB_LISTENERS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:17,421 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,421 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,421 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Deleting job: DEFAULT.hqejbhcnphr2hjanpjgq0g
>
> 2007-08-06 08:41:17,421 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:17,437 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_JOB_DETAILS WHERE JOB_NAME = ? AND
> JOB_GROUP = ?
>
> 2007-08-06 08:41:17,437 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,437 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,DEFAULT) (1,hqejbhcnphr2hjanpjgq0g)
>
> 2007-08-06 08:41:17,453 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_FIRED_TRIGGERS WHERE ENTRY_ID = ?
>
> 2007-08-06 08:41:17,453 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: DELETE FROM QRTZ_FIRED_TRIGGERS WHERE ENTRY_ID = ?
>
> 2007-08-06 08:41:17,453 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,hqejbhcnphr2hjanpjgq0d1186404017843)
>
> 2007-08-06 08:41:17,453 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,hqejbhcnphr2hjanpjgq0d1186404017843)
>
> 2007-08-06 08:41:17,453 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@1f3471d
>
> 2007-08-06 08:41:17,468 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: pool-4-thread-1
>
> 2007-08-06 08:41:17,468 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: pool-4-thread-1
>
> 2007-08-06 08:41:17,468 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,468 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:17,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:17,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404017484) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:17,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404017484) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:17,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:17,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:17,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:17,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:17,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@8fd95d
>
> 2007-08-06 08:41:17,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:17,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:17,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is desired by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' is being obtained: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' given to: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:17,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: UPDATE QRTZ_TRIGGERS SET TRIGGER_STATE = ? WHERE
> (TRIGGER_STATE = ? OR TRIGGER_STATE = ?) AND NEXT_FIRE_TIME < ?
>
> 2007-08-06 08:41:17,562 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404017562) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:17,578 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (2,WAITING) (4,1186404017562) (1,MISFIRED) (3,WAITING)
>
> 2007-08-06 08:41:17,578 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:17,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT MIN(NEXT_FIRE_TIME) AS ALIAS_NXT_FR_TM FROM
> QRTZ_TRIGGERS WHERE TRIGGER_STATE = ? AND NEXT_FIRE_TIME >= 0
>
> 2007-08-06 08:41:17,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:17,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,WAITING)
>
> 2007-08-06 08:41:17,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@8e13ab
>
> 2007-08-06 08:41:17,593 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'JOB_ACCESS' retuned by: ODE_QuartzSchedulerThread
>
> 2007-08-06 08:41:17,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:17,609 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:18,484 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> MisfireHandler: scanning for misfires...
>
> 2007-08-06 08:41:18,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> doRecoverMisfires() callled
>
> 2007-08-06 08:41:18,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getNonManagedTXConnection()
>
> 2007-08-06 08:41:18,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> getConnection (tx=2)
>
> 2007-08-06 08:41:18,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Setting isolation level to 2
>
> 2007-08-06 08:41:18,500 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is desired by:
> QuartzScheduler_ODE-hqejbhcnphr2hjanpjgq0d_MisfireHandler
>
> 2007-08-06 08:41:18,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' is being obtained:
> QuartzScheduler_ODE-hqejbhcnphr2hjanpjgq0d_MisfireHandler
>
> 2007-08-06 08:41:18,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' given to:
> QuartzScheduler_ODE-hqejbhcnphr2hjanpjgq0d_MisfireHandler
>
> 2007-08-06 08:41:18,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> TRIGGER_STATE = ?
>
> 2007-08-06 08:41:18,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> prepareStmt: SELECT TRIGGER_NAME, TRIGGER_GROUP FROM QRTZ_TRIGGERS WHERE
> TRIGGER_STATE = ?
>
> 2007-08-06 08:41:18,515 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,MISFIRED)
>
> 2007-08-06 08:41:18,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> bound (1,MISFIRED)
>
> 2007-08-06 08:41:18,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Found 0 triggers that missed their scheduled fire-time.
>
> 2007-08-06 08:41:18,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> COMMIT: org.apache.ode.utils.LoggingConnectionWrapper@18fcdce
>
> 2007-08-06 08:41:18,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> doRecoverMisfires() returned moreToDo = false
>
> 2007-08-06 08:41:18,531 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> Lock 'TRIGGER_ACCESS' retuned by:
> QuartzScheduler_ODE-hqejbhcnphr2hjanpjgq0d_MisfireHandler
>
> 2007-08-06 08:41:18,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
> 2007-08-06 08:41:18,546 INFO  [STDOUT] DEBUG - GeronimoLog.debug(66) |
> close
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message