Hello,
I found the last release of CloverETL engine slower than the previous one.
Indeed a 45 minutes process with CloverETL Engine 2.1.3 now last 1 hour.
I changed nothing except the Clover ETL Engine.
It does work of course but slower than before
More batchmode option in DB_OUTPUT_TABLE component doesn’t work anymore.
Anyone else has noticed that ?
Thanks.
Hello,
could you please describe the process which now takes longer to complete? Which components are you using etc.?
Thanks!
Jaro
Here is my graph: http://maxani.homeip.net/
Actually I just read two tables (the same one, I mean same metadata) from two databases.
The BUFFER COMPARE component is just a DATAINTERSECTION component I modified just for not processing records that are in the two tables and which have not been modified / updated.
Then the goal of my graph is :
- to add records in the second database if there are new records in the first database PRODUCTION
- to delete records if records have been deleted in the first database
- update records if records have been updated in the first database.
This graph and its BUFFER COMPARE component work great since the first releases of CloverETL.
I admit that I have to disable batchmode of DB_OUTPUT_TABLE component with the last release (2.2) because it doesn’t work.
Indeed I’ve got a “java.lang.NullPointerException” Exception.
I hope you understand me (sorry for my bad english).
Thanks.
I suspect that the slowdown is caused by the turned off batchmode. I tried the batchmode, but it works for me. Could you please post the stacktrace of the NullPointerException?
Thanks!
Go again on http://maxani.homeip.net
You’re gonna find the xml graph file and the debug file generated by log4J.
Thanks.
Hi,
I think I know what’s causing the error with the batchmode (it is fixed in a newer yet unrealeased engine version). I think that as a workaround, you should connect the first output port (port 0) of all DB_OUTPUT_TABLE components with some TRASH component, and assign the connector the same metadata as on the input of the DB_OUTPUT_TABLE…this way you basically trash the records rejected by the DB_OUTPUT_TABLE (they can be rejected by the database or some other error). Please try the workaround and let me know if it works. Thanks!
Jaro
OK.
It seems to work better now with your piece of advice.
Now I’m gonna wait the end of the process to see how long it lasts.
Do you know when the next cloveretl engine will be released approximatively ?
thanks a lot.
The 2.2.1 bugfix release should be out in 1 or 2 weeks. The release will contain the bugfix to your issue with the batchmode.
Jaro
I’m afraid that CloverETL Engine 2.2 is really slower than CloverETL Engine 2.1.3:
Indeed I’ve just executed a simple graph with a table with 280 000 records:
DB_INPUT_TABLE ------> EDGE ------> DELIMITED_DATA_WRITER
The environnement is the same (OS, Network, Oracle database, JDBC driver …)
I use the same graph under Eclipse with CloverGUI.
1st test (3 times) with CloverETL Engine 2.1.3 : average duration = 63s
2nd test (3 times) with CloverETL Engine 2.2 : average duration = 75s
There’s an average diffence of 13s just for one table of 280000 records.
It explains why for a process which lasted for example 3 hour and 30 minutes before, now it lasts 4h30 (a database of 10 000 000 records)
Of course it still works but I can’t use CloverETL Engine 2.2 in production environnement for this reason.
I suppose that there’s a problem with DB_INPUT_TABLE component. (Maybe or surely also with DB_OUTPUT_TABLE component)
Am I the only one who notice that ?
Hello,
we will investigate the slowdown, but it might take some time. Thanks for your input!
Jaro
Hello,
I may have found why there’s a slowdown with last releases of cloverETL Engine. There’s still a slowdown with the very last one 2.3.0.
The last “Forcing garbage collection” step of WatchDog Process seems to last more time than before. I mean the “Forcing garbage collection” step of the last phase of the graph.
Indeed here is the debug log of an execution of a graph with CloverETL Engine 2.1.3 :
--------------------------------------------------------------------------------
Remontée de la table : CORRESPONDANCE_ASG_MDPH
*** CloverETL framework/transformation graph runner ver 2.1, (c) 2002-06 D.Pavlis, released under GNU Lesser General Public License ***
Running with framework version: 2.1 build#410 compiled 23/05/2007 17:14:19
DEBUG [main] - Plugin com.infodb.component loaded.
id - com.infodb.component
version - 2.1.3
provider-name - null
point-id - component - {type=BUFFER_COMPARE, className=com.infodb.component.BufferCompare}
DEBUG [main] - Plugin cz.opensys.oracle loaded.
id - cz.opensys.oracle
version - 2.1.3
provider-name -
point-id - component - {className=cz.opensys.oracle.component.OracleDataReader, type=ORACLE_DATA_READER}
point-id - component - {className=cz.opensys.oracle.component.OracleDataWriter, type=ORACLE_DATA_WRITER}
DEBUG [main] - Plugin org.jetel.component loaded.
id - org.jetel.component
version - 2.1.3
provider-name - null
point-id - component - {type=DATA_READER, className=org.jetel.component.DataReader}
point-id - component - {type=DATA_WRITER, className=org.jetel.component.DataWriter}
point-id - component - {type=DELIMITED_DATA_READER, className=org.jetel.component.DelimitedDataReader}
point-id - component - {type=DELIMITED_DATA_WRITER, className=org.jetel.component.DelimitedDataWriter}
point-id - component - {type=SIMPLE_COPY, className=org.jetel.component.SimpleCopy}
point-id - component - {type=CONCATENATE, className=org.jetel.component.Concatenate}
point-id - component - {type=SIMPLE_GATHER, className=org.jetel.component.SimpleGather}
point-id - component - {type=REFORMAT, className=org.jetel.component.Reformat}
point-id - component - {type=DB_INPUT_TABLE, className=org.jetel.component.DBInputTable}
point-id - component - {type=SORT, className=org.jetel.component.Sort}
point-id - component - {type=DB_OUTPUT_TABLE, className=org.jetel.component.DBOutputTable}
point-id - component - {type=FIXLEN_DATA_WRITER, className=org.jetel.component.FixLenDataWriter}
point-id - component - {type=DEDUP, className=org.jetel.component.Dedup}
point-id - component - {type=FIXLEN_DATA_READER, className=org.jetel.component.FixLenDataReader}
point-id - component - {type=MERGE, className=org.jetel.component.Merge}
point-id - component - {type=MERGE_JOIN, className=org.jetel.component.MergeJoin}
point-id - component - {type=EXT_MERGE_JOIN, className=org.jetel.component.MergeJoin}
point-id - component - {type=SORTED_JOIN, className=org.jetel.component.MergeJoin}
point-id - component - {type=TRASH, className=org.jetel.component.Trash}
point-id - component - {type=DB_EXECUTE, className=org.jetel.component.DBExecute}
point-id - component - {type=HASH_JOIN, className=org.jetel.component.HashJoin}
point-id - component - {type=EXT_HASH_JOIN, className=org.jetel.component.HashJoin}
point-id - component - {type=CHECK_FOREIGN_KEY, className=org.jetel.component.CheckForeignKey}
point-id - component - {type=DBF_DATA_READER, className=org.jetel.component.DBFDataReader}
point-id - component - {type=EXT_FILTER, className=org.jetel.component.ExtFilter}
point-id - component - {type=EXT_SORT, className=org.jetel.component.ExtSort}
point-id - component - {type=PARTITION, className=org.jetel.component.Partition}
point-id - component - {type=DATA_INTERSECTION, className=org.jetel.component.DataIntersection}
point-id - component - {type=AGGREGATE, className=org.jetel.component.Aggregate}
point-id - component - {type=SYS_EXECUTE, className=org.jetel.component.SystemExecute}
point-id - component - {type=KEY_GEN, className=org.jetel.component.KeyGenerator}
point-id - component - {type=APROX_MERGE_JOIN, className=org.jetel.component.AproxMergeJoin}
point-id - component - {type=DBJOIN, className=org.jetel.component.DBJoin}
point-id - component - {type=XLS_READER, className=org.jetel.component.XLSReader}
point-id - component - {type=XLS_WRITER, className=org.jetel.component.XLSWriter}
point-id - component - {type=CLOVER_WRITER, className=org.jetel.component.CloverDataWriter}
point-id - component - {type=CLOVER_READER, className=org.jetel.component.CloverDataReader}
point-id - component - {className=org.jetel.component.MysqlDataReader, type=MYSQL_DATA_READER}
point-id - component - {className=org.jetel.component.MysqlDataWriter, type=MYSQL_DATA_WRITER}
point-id - component - {className=org.jetel.component.StructureWriter, type=STRUCTURE_WRITER}
point-id - component - {className=org.jetel.component.Normalizer, type=NORMALIZER}
point-id - component - {className=org.jetel.component.Denormalizer, type=DENORMALIZER}
point-id - component - {className=org.jetel.component.JmsReader, type=JMS_READER}
point-id - component - {className=org.jetel.component.JmsWriter, type=JMS_WRITER}
point-id - component - {className=org.jetel.component.LookupJoin, type=LOOKUP_JOIN}
point-id - component - {className=org.jetel.component.LookupTableReaderWriter, type=LOOKUP_TABLE_READER_WRITER}
point-id - component - {className=org.jetel.component.DataGenerator, type=DATA_GENERATOR}
point-id - component - {className=org.jetel.component.MultiLevelReader, type=MULTI_LEVEL_READER}
point-id - component - {className=org.jetel.component.SequenceChecker, type=SEQUENCE_CHECKER}
DEBUG [main] - Plugin org.jetel.connection loaded.
id - org.jetel.connection
version - 2.1.3
provider-name - null
point-id - connection - {className=org.jetel.connection.DBConnection, type=JDBC}
point-id - connection - {className=org.jetel.connection.JmsConnection, type=JMS}
DEBUG [main] - Plugin org.jetel.lookup loaded.
id - org.jetel.lookup
version - 2.1.3
provider-name - null
point-id - lookup - {className=org.jetel.lookup.SimpleLookupTable, type=simpleLookup}
point-id - lookup - {className=org.jetel.lookup.DBLookupTable, type=dbLookup}
DEBUG [main] - Plugin org.jetel.sequence loaded.
id - org.jetel.sequence
version - 2.1.3
provider-name - null
point-id - sequence - {className=org.jetel.sequence.SimpleSequence, type=SIMPLE_SEQUENCE}
point-id - sequence - {className=org.jetel.sequence.PrimitiveSequence, type=PRIMITIVE_SEQUENCE}
DEBUG [main] - Plugin org.jetel.thirdparty loaded.
id - org.jetel.thirdparty
version - 2.1.3
provider-name - null
point-id - component - {type=XML_EXTRACT, className=org.jetel.component.XMLExtract}
point-id - component - {type=FILTER, className=org.jetel.component.Filter}
point-id - component - {type=LDAP_READER, className=com.linagora.component.LdapReader}
point-id - component - {type=LDAP_WRITER, className=com.linagora.component.LdapWriter}
Graph definition file: graphs/infocentre2.grf
INFO [main] - Checking graph configuration…
WARN [main] - unable to set FetchDirection & FetchSize for DB connection [DBConnection1]
WARN [main] - unable to set FetchDirection & FetchSize for DB connection [DBConnection0]
INFO [main] - Initializing DB connection:
INFO [main] - DBConnection driver[oracle.jdbc.OracleDriver]:url[jdbc:oracle:thin:@guenievre:1521:or68mdph]:user[civi] … OK
INFO [main] - Initializing DB connection:
INFO [main] - DBConnection driver[oracle.jdbc.OracleDriver]:url[jdbc:oracle:thin:@guenievre:1521:mvbo]:user[perc] … OK
INFO [main] - Starting WatchDog thread …
INFO [WatchDog] - Thread started.
INFO [WatchDog] - Running on 1 CPU(s) max available memory for JVM 65088 KB
INFO [WatchDog] - [Clover] Initializing phase: 0
DEBUG [WatchDog] - initializing edges:
DEBUG [WatchDog] - all edges initialized successfully…
DEBUG [WatchDog] - initializing nodes:
DEBUG [WatchDog] - DEDUP0 …OK
WARN [WatchDog] - unable to set FetchDirection & FetchSize for DB connection [DBConnection1]
DEBUG [WatchDog] - INFOCENTRE …OK
WARN [WatchDog] - unable to set FetchDirection & FetchSize for DB connection [DBConnection0]
DEBUG [WatchDog] - PRODUCTION …OK
INFO [WatchDog] - [Clover] phase: 0 initialized successfully.
INFO [WatchDog] - Starting up all nodes in phase [0]
DEBUG [WatchDog] - DEDUP0 … started
DEBUG [WatchDog] - INFOCENTRE … started
DEBUG [WatchDog] - PRODUCTION … started
INFO [WatchDog] - Sucessfully started all nodes in phase!
INFO [WatchDog] - Execution of phase [0] successfully finished - elapsed time(sec): 1
INFO [WatchDog] - ---------------------** Start of tracking Log for phase [0] **-------------------
INFO [WatchDog] - Time: 25/09/07 15:50:47
INFO [WatchDog] - Node Status Port #Records #KB Rec/s KB/s
INFO [WatchDog] - ----------------------------------------------------------------------------------
INFO [WatchDog] - DEDUP0 FINISHED_O
INFO [WatchDog] - %CPU:-1.9 In:0 0 0 0 0
INFO [WatchDog] - Out:0 0 0 0 0
INFO [WatchDog] - INFOCENTRE FINISHED_O
INFO [WatchDog] - %CPU:-1.9 Out:0 0 0 0 0
INFO [WatchDog] - PRODUCTION FINISHED_O
INFO [WatchDog] - %CPU:-1.9 Out:0 0 0 0 0
INFO [WatchDog] - ---------------------------------** End of Log **--------------------------------
INFO [WatchDog] - Forcing garbage collection …
INFO [WatchDog] - [Clover] Initializing phase: 1
DEBUG [WatchDog] - initializing edges:
DEBUG [WatchDog] - all edges initialized successfully…
DEBUG [WatchDog] - initializing nodes:
DEBUG [WatchDog] - BUFFER_COMPARE0 …OK
DEBUG [WatchDog] - TRASH0 …OK
DEBUG [WatchDog] - TRASH1 …OK
DEBUG [WatchDog] - TRASH2 …OK
INFO [WatchDog] - [Clover] phase: 1 initialized successfully.
INFO [WatchDog] - Starting up all nodes in phase [1]
DEBUG [WatchDog] - BUFFER_COMPARE0 … started
DEBUG [WatchDog] - TRASH0 … started
DEBUG [WatchDog] - TRASH1 … started
DEBUG [WatchDog] - TRASH2 … started
INFO [WatchDog] - Sucessfully started all nodes in phase!
INFO [WatchDog] - Execution of phase [1] successfully finished - elapsed time(sec): 1
INFO [WatchDog] - ---------------------** Start of tracking Log for phase [1] **-------------------
INFO [WatchDog] - Time: 25/09/07 15:50:48
INFO [WatchDog] - Node Status Port #Records #KB Rec/s KB/s
INFO [WatchDog] - ----------------------------------------------------------------------------------
INFO [WatchDog] - BUFFER_COMPARE0 FINISHED_O
INFO [WatchDog] - %CPU:-1.9 In:0 0 0 0 0
INFO [WatchDog] - In:1 0 0 0 0
INFO [WatchDog] - Out:0 0 0 0 0
INFO [WatchDog] - Out:1 0 0 0 0
INFO [WatchDog] - Out:2 0 0 0 0
INFO [WatchDog] - TRASH0 FINISHED_O
INFO [WatchDog] - %CPU:-1.9 In:0 0 0 0 0
INFO [WatchDog] - TRASH1 FINISHED_O
INFO [WatchDog] - %CPU:-1.9 In:0 0 0 0 0
INFO [WatchDog] - TRASH2 FINISHED_O
INFO [WatchDog] - %CPU:-1.9 In:0 0 0 0 0
INFO [WatchDog] - ---------------------------------** End of Log **--------------------------------
INFO [WatchDog] - Forcing garbage collection …
INFO [WatchDog] - -----------------------** Summary of Phases execution **---------------------
INFO [WatchDog] - Phase# Finished Status RunTime(sec) MemoryAllocation(KB)
INFO [WatchDog] - 0 0 1 1756
INFO [WatchDog] - 1 0 1 1202
INFO [WatchDog] - ------------------------------** End of Summary **---------------------------
INFO [main] - WatchDog thread finished - total execution time: 2 (sec)
WARN [main] - DBConnection0 - close operation failed.
WARN [main] - DBConnection1 - close operation failed.
INFO [main] - Graph execution finished successfully
Execution of graph successful !
And here is the debug log of an execution of the same graph with CloverETL Engine 2.3.0 :
--------------------------------------------------------------------------------
Remontée de la table : CORRESPONDANCE_ASG_MDPH
*** CloverETL framework/transformation graph runner ver 2.3, (c) 2002-06 D.Pavlis, released under GNU Lesser General Public License ***
Running with framework version: 2.3 build#${build.number} compiled ${TODAY}
DEBUG [main] - Plugin com.infodb.component loaded.
id - com.infodb.component
version - 2.3.0
provider-name - null
component { type = BUFFER_COMPARE; className = com.infodb.component.BufferCompare; }
DEBUG [main] - Plugin org.jetel.bulkloader loaded.
id - org.jetel.bulkloader
version - 2.3.0
provider-name -
component { type = ORACLE_DATA_READER; className = org.jetel.component.OracleDataReader; }
component { type = ORACLE_DATA_WRITER; className = org.jetel.component.OracleDataWriter; }
component { type = MYSQL_DATA_READER; className = org.jetel.component.MysqlDataReader; }
component { type = MYSQL_DATA_WRITER; className = org.jetel.component.MysqlDataWriter; }
component { type = DB2_DATA_WRITER; className = org.jetel.component.DB2DataWriter; }
component { type = INFORMIX_DATA_WRITER; className = org.jetel.component.InformixDataWriter; }
component { type = MS_SQL_DATA_WRITER; className = org.jetel.component.MsSqlDataWriter; }
DEBUG [main] - Plugin org.jetel.component loaded.
id - org.jetel.component
version - 2.3.0
provider-name - null
component { type = DATA_READER; className = org.jetel.component.DataReader; }
component { type = DATA_WRITER; className = org.jetel.component.DataWriter; }
component { type = DELIMITED_DATA_READER; className = org.jetel.component.DelimitedDataReader; }
component { type = DELIMITED_DATA_WRITER; className = org.jetel.component.DelimitedDataWriter; }
component { type = SIMPLE_COPY; className = org.jetel.component.SimpleCopy; }
component { type = CONCATENATE; className = org.jetel.component.Concatenate; }
component { type = SIMPLE_GATHER; className = org.jetel.component.SimpleGather; }
component { type = REFORMAT; className = org.jetel.component.Reformat; }
component { type = DB_INPUT_TABLE; className = org.jetel.component.DBInputTable; }
component { type = SORT; className = org.jetel.component.Sort; }
component { type = DB_OUTPUT_TABLE; className = org.jetel.component.DBOutputTable; }
component { type = FIXLEN_DATA_WRITER; className = org.jetel.component.FixLenDataWriter; }
component { type = DEDUP; className = org.jetel.component.Dedup; }
component { type = FIXLEN_DATA_READER; className = org.jetel.component.FixLenDataReader; }
component { type = MERGE; className = org.jetel.component.Merge; }
component { type = MERGE_JOIN; className = org.jetel.component.MergeJoin; }
component { type = EXT_MERGE_JOIN; className = org.jetel.component.MergeJoin; }
component { type = SORTED_JOIN; className = org.jetel.component.MergeJoin; }
component { type = TRASH; className = org.jetel.component.Trash; }
component { type = DB_EXECUTE; className = org.jetel.component.DBExecute; }
component { type = HASH_JOIN; className = org.jetel.component.HashJoin; }
component { type = EXT_HASH_JOIN; className = org.jetel.component.HashJoin; }
component { type = CHECK_FOREIGN_KEY; className = org.jetel.component.CheckForeignKey; }
component { type = DBF_DATA_READER; className = org.jetel.component.DBFDataReader; }
component { type = EXT_FILTER; className = org.jetel.component.ExtFilter; }
component { type = EXT_SORT; className = org.jetel.component.ExtSort; }
component { type = PARTITION; className = org.jetel.component.Partition; }
component { type = DATA_INTERSECTION; className = org.jetel.component.DataIntersection; }
component { type = AGGREGATE; className = org.jetel.component.Aggregate; }
component { type = SYS_EXECUTE; className = org.jetel.component.SystemExecute; }
component { type = KEY_GEN; className = org.jetel.component.KeyGenerator; }
component { type = APROX_MERGE_JOIN; className = org.jetel.component.AproxMergeJoin; }
component { type = DBJOIN; className = org.jetel.component.DBJoin; }
component { type = XLS_READER; className = org.jetel.component.XLSReader; }
component { type = XLS_WRITER; className = org.jetel.component.XLSWriter; }
component { type = CLOVER_WRITER; className = org.jetel.component.CloverDataWriter; }
component { type = CLOVER_READER; className = org.jetel.component.CloverDataReader; }
component { type = STRUCTURE_WRITER; className = org.jetel.component.StructureWriter; }
component { type = NORMALIZER; className = org.jetel.component.Normalizer; }
component { type = DENORMALIZER; className = org.jetel.component.Denormalizer; }
component { type = JMS_READER; className = org.jetel.component.JmsReader; }
component { type = JMS_WRITER; className = org.jetel.component.JmsWriter; }
component { type = LOOKUP_JOIN; className = org.jetel.component.LookupJoin; }
component { type = LOOKUP_TABLE_READER_WRITER; className = org.jetel.component.LookupTableReaderWriter; }
component { type = DATA_GENERATOR; className = org.jetel.component.DataGenerator; }
component { type = MULTI_LEVEL_READER; className = org.jetel.component.MultiLevelReader; }
component { type = SEQUENCE_CHECKER; className = org.jetel.component.SequenceChecker; }
component { type = TEXT_TABLE_WRITER; className = org.jetel.component.TextTableWriter; }
component { type = XML_XPATH_READER; className = org.jetel.component.XmlXPathReader; }
component { type = PACEMAKER; className = org.jetel.component.Pacemaker; }
DEBUG [main] - Plugin org.jetel.connection loaded.
id - org.jetel.connection
version - 2.3.0
provider-name - null
connection { type = JDBC; className = org.jetel.connection.DBConnection; }
connection { type = JMS; className = org.jetel.connection.JmsConnection; }
DEBUG [main] - Plugin org.jetel.jdbc loaded.
id - org.jetel.jdbc
version - 2.3.0
provider-name - null
jdbcDriver { dbDriver = org.gjt.mm.mysql.Driver; urlHint = jdbc:mysql://hostname:3306/database; name = MySQL; database = MYSQL; driverLibrary = lib/mysql/mysql-connector-java-3.0.11-stable-bin.jar; }
DEBUG [main] - Plugin org.jetel.lookup loaded.
id - org.jetel.lookup
version - 2.3.0
provider-name - null
lookup { type = simpleLookup; className = org.jetel.lookup.SimpleLookupTable; }
lookup { type = dbLookup; className = org.jetel.lookup.DBLookupTable; }
lookup { type = rangeLookup; className = org.jetel.lookup.RangeLookupTable; }
DEBUG [main] - Plugin org.jetel.sequence loaded.
id - org.jetel.sequence
version - 2.3.0
provider-name - null
sequence { type = SIMPLE_SEQUENCE; className = org.jetel.sequence.SimpleSequence; }
sequence { type = PRIMITIVE_SEQUENCE; className = org.jetel.sequence.PrimitiveSequence; }
DEBUG [main] - Plugin org.jetel.thirdparty loaded.
id - org.jetel.thirdparty
version - 2.3.0
provider-name - null
component { type = XML_EXTRACT; className = org.jetel.component.XMLExtract; }
component { type = FILTER; className = org.jetel.component.Filter; }
component { type = LDAP_READER; className = com.linagora.component.LdapReader; }
component { type = LDAP_WRITER; className = com.linagora.component.LdapWriter; }
DEBUG [main] - Plugin org.jetel.tlfunction loaded.
id - org.jetel.tlfunction
version - 2.3.0
provider-name - null
tlfunction { className = org.jetel.interpreter.extensions.MathLib; function = sqrt,log,log10,exp,round,pow,pi,e,random; libraryName = math; }
tlfunction { className = org.jetel.interpreter.extensions.DateLib; function = today,dateadd,datediff,trunc; libraryName = date; }
tlfunction { className = org.jetel.interpreter.extensions.StringLib; function = concat,uppercase,lowercase,substring,left,right,trim,length,soundex,replace,split,char_at,is_blank,is_ascii,is_number,is_integer,is_date,remove_diacritic; libraryName = string; }
tlfunction { className = org.jetel.interpreter.extensions.ConvertLib; function = num2str,date2str,str2date,date2num,str2num; libraryName = convert; }
Graph definition file: graphs/infocentre2.grf
INFO [main] - Checking graph configuration…
INFO [main] - Initializing DB connection:
INFO [main] - DBConnection driver[oracle.jdbc.OracleDriver]:url[jdbc:oracle:thin:@guenievre:1521:or68mdph]:user[civi] … OK
INFO [main] - Initializing DB connection:
INFO [main] - DBConnection driver[oracle.jdbc.OracleDriver]:url[jdbc:oracle:thin:@guenievre:1521:mvbo]:user[perc] … OK
INFO [main] - Starting WatchDog thread …
INFO [WatchDog] - Thread started.
INFO [WatchDog] - Running on 1 CPU(s) max available memory for JVM 65088 KB
INFO [WatchDog] - [Clover] Initializing phase: 0
DEBUG [WatchDog] - initializing edges:
DEBUG [WatchDog] - all edges initialized successfully…
DEBUG [WatchDog] - initializing nodes:
DEBUG [WatchDog] - DEDUP0 …OK
DEBUG [WatchDog] - INFOCENTRE …OK
DEBUG [WatchDog] - PRODUCTION …OK
INFO [WatchDog] - [Clover] phase: 0 initialized successfully.
INFO [WatchDog] - Starting up all nodes in phase [0]
DEBUG [WatchDog] - DEDUP0 … started
DEBUG [WatchDog] - INFOCENTRE … started
DEBUG [WatchDog] - PRODUCTION … started
INFO [WatchDog] - Sucessfully started all nodes in phase!
DEBUG [INFOCENTRE] - DBConenction (DBConnection1), component [INFOCENTRE] attempts to connect to the database
DEBUG [PRODUCTION] - DBConenction (DBConnection0), component [PRODUCTION] attempts to connect to the database
DEBUG [PRODUCTION] - unable to set FetchDirection & FetchSize for DB connection [DBConnection0]
DEBUG [INFOCENTRE] - unable to set FetchDirection & FetchSize for DB connection [DBConnection1]
INFO [WatchDog] - Execution of phase [0] successfully finished - elapsed time(sec): 1
INFO [WatchDog] - ----------------------** Final tracking Log for phase [0] **---------------------
INFO [WatchDog] - Time: 25/09/07 15:51:12
INFO [WatchDog] - Node Status Port #Records #KB Rec/s KB/s
INFO [WatchDog] - ----------------------------------------------------------------------------------
INFO [WatchDog] - DEDUP0 FINISHED_OK
INFO [WatchDog] - %cpu:… In:0 0 0 0 0
INFO [WatchDog] - Out:0 0 0 0 0
INFO [WatchDog] - INFOCENTRE FINISHED_OK
INFO [WatchDog] - %cpu:… Out:0 0 0 0 0
INFO [WatchDog] - PRODUCTION FINISHED_OK
INFO [WatchDog] - %cpu:… Out:0 0 0 0 0
INFO [WatchDog] - ---------------------------------** End of Log **--------------------------------
INFO [WatchDog] - Forcing garbage collection …
INFO [WatchDog] - [Clover] Initializing phase: 1
DEBUG [WatchDog] - initializing edges:
DEBUG [WatchDog] - all edges initialized successfully…
DEBUG [WatchDog] - initializing nodes:
DEBUG [WatchDog] - BUFFER_COMPARE0 …OK
DEBUG [WatchDog] - TRASH0 …OK
DEBUG [WatchDog] - TRASH1 …OK
DEBUG [WatchDog] - TRASH2 …OK
INFO [WatchDog] - [Clover] phase: 1 initialized successfully.
INFO [WatchDog] - Starting up all nodes in phase [1]
DEBUG [WatchDog] - BUFFER_COMPARE0 … started
DEBUG [WatchDog] - TRASH0 … started
DEBUG [WatchDog] - TRASH1 … started
DEBUG [WatchDog] - TRASH2 … started
INFO [WatchDog] - Sucessfully started all nodes in phase!
INFO [WatchDog] - Execution of phase [1] successfully finished - elapsed time(sec): 1
INFO [WatchDog] - ----------------------** Final tracking Log for phase [1] **---------------------
INFO [WatchDog] - Time: 25/09/07 15:51:13
INFO [WatchDog] - Node Status Port #Records #KB Rec/s KB/s
INFO [WatchDog] - ----------------------------------------------------------------------------------
INFO [WatchDog] - BUFFER_COMPARE0 FINISHED_OK
INFO [WatchDog] - %cpu:… In:0 0 0 0 0
INFO [WatchDog] - In:1 0 0 0 0
INFO [WatchDog] - Out:0 0 0 0 0
INFO [WatchDog] - Out:1 0 0 0 0
INFO [WatchDog] - Out:2 0 0 0 0
INFO [WatchDog] - TRASH0 FINISHED_OK
INFO [WatchDog] - %cpu:… In:0 0 0 0 0
INFO [WatchDog] - TRASH1 FINISHED_OK
INFO [WatchDog] - %cpu:… In:0 0 0 0 0
INFO [WatchDog] - TRASH2 FINISHED_OK
INFO [WatchDog] - %cpu:… In:0 0 0 0 0
INFO [WatchDog] - ---------------------------------** End of Log **--------------------------------
INFO [WatchDog] - Forcing garbage collection …
INFO [WatchDog] - -----------------------** Summary of Phases execution **---------------------
INFO [WatchDog] - Phase# Finished Status RunTime(sec) MemoryAllocation(KB)
INFO [WatchDog] - 0 FINISHED_OK 1 1480
INFO [WatchDog] - 1 FINISHED_OK 1 1170
INFO [WatchDog] - ------------------------------** End of Summary **---------------------------
INFO [main] - WatchDog thread finished - total execution time: 7 (sec)
INFO [main] - Graph execution finished successfully
Execution of graph successful !
As you can see with 2.1.3 the process lasts 2s and with 2.3.0 it lasts 7s.
The “Forcing garbage collection” step of the first phase of both graphs seems to be equal.
On the contrary the “Forcing garbage collection” step of the second phase (actually the last one) are not equal.
In 2.1.3 release it lasts 1 second and with 2.3.0 it lasts 6 seconds.
I work with about 400 tables so with a difference of 5s just for this step :
400*5 seconds = 2000 seconds => half an hour !
I hope that you understand me and that it’s gonna help you for next release.
I really would like to find again my precious seconds 
Thank you.
Hello Maxani,
try to use -noJMX switch for runGraph. Let me know if it help you.
Martin
Hello,
YES I’ve found again my precious seconds !
Now can you explain me what’s the goal of the parameter “-noJMX” ?
I didn’t find any explanation on the wiki or the javadoc.
Can you also talk me about the parameters “-mbean” and “-stdin” ?
Thanks a lot for your help.
The meaning of the ‘-noJMX’ switch is in the ability to turn off sending tracking information. Of course if you run graph in the product system, you usually doesn’t need to track graph in runtime. So now it is recommended to use this switch in these cases, since the implementation of JMX interface demands small timeout in the end of graph run. I hope that the next version will be able to recognize that there is now JMX client and this timeout will be skipped.
‘-mbean ’ switch is not in fact public switch useful for end user - via this parameter you can change name of registered mbean for JMX purpose
‘-stdin’ means that the xml graph file is awaited in the standard input of runGraph application
Martin
OK
Thanks for all these explanations.
See you.