Graph with oracle db connection never completes

I’m running a graph in server that runs fine from the command line using 2.8.1 downloaded from source forge. In server it stops around initializing the database connection. The last message I get in the server logs is: “Try to use another jdbc specific”.

This seems like it might be related to:
viewtopic.php?f=3&t=1797

Any ideas what might be causing this?

2010-01-15 22:36:12,764 INFO 1900546 [http-13280-2] Graph properties:{SANDBOX_CODE_PROPERTY_KEY=proj, GRAPH_FILE_PROPERTY_KEY=graph/test.grf, RUN_ID=1900546, SANDBOX_simple=/home/me/simple, SANDBOX_ROOT_PROPERTY_KEY=/home/me/proj, PROJECT_DIR=/home/me/proj/, SANDBOX_proj=/home/me/proj, SANDBOX_default=/home/me/apache-tomcat-6.0.20/webapps/clover/WEB-INF/testsandbox}
2010-01-15 22:36:12,764 INFO 1900546 [http-13280-2] create new graph instance Graph#proj~graph/test.grf
2010-01-15 22:36:12,809 INFO 1900546 [http-13280-2] Executor configuration; using graph config properties:{}
2010-01-15 22:36:12,809 INFO 1900546 [http-13280-2] Executor configuration; using graph passed properties:null
2010-01-15 22:36:12,809 INFO 1900546 [http-13280-2] Graph configuration checking is skipped.
2010-01-15 22:36:12,809 INFO 1900546 [http-13280-2] Graph initialization (test)
2010-01-15 22:36:12,809 WARN 1900546 [http-13280-2] Graph element test[1263533009707] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:12,810 WARN 1900546 [http-13280-2] Graph element [_DICTIONARY] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:12,810 INFO 1900546 [http-13280-2] Initializing connection:
2010-01-15 22:36:12,810 WARN 1900546 [http-13280-2] Graph element DBConnection driver[null]:jndi[null]:url[null]:user[null] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] DBConnection driver[org.jetel.connection.jdbc.driver.JdbcDriver@7fd1c60]:jndi[null]:url[jdbc:oracle:thin:@//oracle-int.chalybs.net:1521/merlin1]:user[tom] … OK
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] *** TRANSFORMATION GRAPH CONFIGURATION ***

2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] — Phase [0] —
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] … nodes …
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] SYS_EXECUTE0 : phase: 0
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] … edges …
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] — end phase —
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] — Phase [1] —
2010-01-15 22:36:12,811 INFO 1900546 [http-13280-2] … nodes …
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] DATA_WRITER1 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] DBJOIN0 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] EXT_FILTER0 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] REFORMAT0 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] TRASH0 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] XML_EXTRACT0 : phase: 1
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] … edges …
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] Edge5 type: direct
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] Edge0 type: direct
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] Edge2 type: direct
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] Edge3 type: direct
2010-01-15 22:36:12,812 INFO 1900546 [http-13280-2] Edge4 type: direct
2010-01-15 22:36:12,813 INFO 1900546 [http-13280-2] — end phase —
2010-01-15 22:36:12,813 INFO 1900546 [http-13280-2] *** END OF GRAPH LIST ***
2010-01-15 22:36:12,813 INFO 1900546 [http-13280-2] ready to execute watchdog
2010-01-15 22:36:12,813 INFO 1900546 [http-13280-2] register MBean with name:org.jetel.graph.runtime:type=CLOVERJMX_1263533009707_1900546
2010-01-15 22:36:12,813 INFO 1900546 [http-13280-2] graph started; runId=1900546
2010-01-15 22:36:12,817 INFO 1900546 [WatchDog] *** TRANSFORMATION GRAPH CONFIGURATION ***

2010-01-15 22:36:12,817 INFO 1900546 [WatchDog] — Phase [0] —
2010-01-15 22:36:12,817 INFO 1900546 [WatchDog] … nodes …
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] SYS_EXECUTE0 : phase: 0
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] … edges …
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] — end phase —
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] — Phase [1] —
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] … nodes …
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] DATA_WRITER1 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] DBJOIN0 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] EXT_FILTER0 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] REFORMAT0 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] TRASH0 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] XML_EXTRACT0 : phase: 1
2010-01-15 22:36:12,818 INFO 1900546 [WatchDog] … edges …
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] Edge5 type: direct
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] Edge0 type: direct
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] Edge2 type: direct
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] Edge3 type: direct
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] Edge4 type: direct
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] — end phase —
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] *** END OF GRAPH LIST ***
2010-01-15 22:36:12,819 WARN 1900546 [WatchDog] Graph element [0] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:12,819 INFO 1900546 [WatchDog] [Clover] Initializing phase: 0
2010-01-15 22:36:12,819 WARN 1900546 [WatchDog] Graph element [SYS_EXECUTE0] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:12,820 INFO 1900546 [WatchDog] [Clover] phase: 0 initialized successfully.
2010-01-15 22:36:12,820 INFO 1900546 [WatchDog] Starting up all nodes in phase [0]
2010-01-15 22:36:12,820 INFO 1900546 [http-13280-2] events created [GraphServerEvent#GRAPH_STARTED user=User#131072:clover runId=1900546]
2010-01-15 22:36:12,821 INFO 1900546 [http-13280-2] add JMX notification listener for:org.jetel.graph.runtime:type=CLOVERJMX_1263533009707_1900546
2010-01-15 22:36:12,878 INFO 1900546 [WatchDog] Successfully started all nodes in phase!
2010-01-15 22:36:12,878 INFO 1900546 [SYS_EXECUTE0] Executing command: “sh /home/me/apache-tomcat-6.0.20/temp/tmp55999.bat”
2010-01-15 22:36:12,996 INFO 1900546 [SYS_EXECUTE0.SendDataToConsole] skipping download data-in/CLU_20100114.zip exists
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] ----------------------** Final tracking Log for phase [0] **---------------------
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] Time: 15/01/10 22:36:13
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] Node Status Port #Records #KB Rec/s KB/s
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] ---------------------------------------------------------------------------------
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] SYS_EXECUTE0 FINISHED_OK
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] %cpu:…
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] ---------------------------------** End of Log **--------------------------------
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] Execution of phase [0] successfully finished - elapsed time(sec): 0
2010-01-15 22:36:13,006 WARN 1900546 [WatchDog] Graph element [1] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,006 INFO 1900546 [WatchDog] [Clover] Initializing phase: 1
2010-01-15 22:36:13,006 WARN 1900546 [WatchDog] Graph element [Edge5] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,007 WARN 1900546 [WatchDog] Graph element [Edge0] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,007 WARN 1900546 [WatchDog] Graph element [Edge2] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,007 WARN 1900546 [WatchDog] Graph element [Edge3] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,008 WARN 1900546 [WatchDog] Graph element [Edge4] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,008 WARN 1900546 [WatchDog] Graph element [DATA_WRITER1] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,010 WARN 1900546 [WatchDog] Graph element [DBJOIN0] is not checked by checkConfig() method. Please call TransformationGraph.checkConfig() first.
2010-01-15 22:36:13,073 WARN 1900546 [WatchDog] Optimizing connection failed: READ_COMMITTED and SERIALIZABLE are the only valid transaction levels
2010-01-15 22:36:13,073 WARN 1900546 [WatchDog] Try to use another jdbc specific

here is my graph:

?xml version=“1.0” encoding=“UTF-8”?>







<![CDATA[if [ -f “${DATAIN_DIR}”/CLU_`date2str(dateadd(today(),-1,day),“yyyyMMdd”)`.zip ]
then
echo “skipping download data-in/CLU_`date2str(dateadd(today(),-1,day),“yyyyMMdd”)`.zip exists”;
else
wget -O “${DATAIN_DIR}”/CLU_`date2str(dateadd(today(),-1,day),“yyyyMMdd”)`.zip ‘ftp://user:pass@ftp.macrovision.com/feed/CLU_’`date2str(dateadd(today(),-1,day),“yyyyMMdd”)`.zip;
fi]]>






<![CDATA[$0.hash_code != $0.old_code]]>




<![CDATA[ ]]>







dbDriver=oracle.jdbc.driver.OracleDriver
user=user
password=pass
name=oracle
dbURL=jdbc:oracle:thin:@//oracle.server.net:1521/stuff
jdbcSpecific=ORACLE

Hi,

these two messages mean, that DB doesn’t support READ_UNCOMMITED transaction isolation level. Clover tries to set this level to achieve faster reading from the database.
It’s not vital and graph initialization goes on.
2010-01-15 22:36:13,073 WARN 1900546 [WatchDog] Optimizing connection failed: READ_COMMITTED and SERIALIZABLE are the only valid transaction levels
2010-01-15 22:36:13,073 WARN 1900546 [WatchDog] Try to use another jdbc specific

There is another problem which causes, that component can’t be initialized.
In this case it was transformation class of DBJOIN component, which wasn’t on server CLASSPATH.

The error handling/reporting will be extended in 2.8.2 version of Clover Server - which should help to find the cause of such problem easier.

Martin

This turned out to be a problem with missing dependencies which didn’t surface via the typical ClassNotFound exception.