ode-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Fernando Lozano" <fernando.loz...@cinetconsult.com>
Subject Error using Ode on JBoss with Oracle
Date Mon, 06 Aug 2007 12:47:23 GMT
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