understanding delay in Director log

austin_316 · Post by **austin_316** » Mon Dec 16, 2013 11:16 pm

Hi,
We have a job with three stages.

OracleConnector ->Copy->OracleConnector.

The job does a simple pull from Source. And in the target we INSERT the records with a DELETE statement defined in BeforeSQL Statement .

When I observe this particular job there is a log showing the configuration file. But this log is being shown after 30mins. (9:05:24 PM as shown in the below logs) Can someone help me understand what exactly is happening here? When I observe the other jobs with similar design this log is shown after 2-3secs maximum.

There are only 2000 records being fetched and deleted/inserted into the target. Even the other jobs which fetches more than 100,000 records is finished in less than 10mins. But the above job takes more than 40mins.

8:33:30 PM 12/16/2013 Environment variable settings: (...)
8:33:31 PM 12/16/2013 Parallel job initiated
8:33:31 PM 12/16/2013 Parallel job default NLS map ISO-8859-1, default locale OFF
8:33:32 PM 12/16/2013 main_program: IBM WebSphere DataStage Enterprise Edition 8.5.0.6152(...)
8:33:32 PM 12/16/2013 main_program: conductor uname: -s=AIX; -r=1; -v=6; -n=dsg1; -m=00F785DE4C00
8:33:32 PM 12/16/2013 main_program: orchgeneral: loaded(...)
8:33:34 PM 12/16/2013 SRC_ORACLE_STG: The connector connected to Oracle server PBWODS.
8:33:34 PM 12/16/2013 SRC_ORACLE_STG: The connector was configured to run in parallel mode on 2 nodes, but the partitioned reads were not enabled. The connector will run in sequential mode.
8:33:34 PM 12/16/2013 SRC_ORACLE_STG: The connector will run in sequential mode.
8:33:34 PM 12/16/2013 SRC_ORACLE_STG: The connector will use the following SELECT statement at runtime: SELECT(...)
8:33:35 PM 12/16/2013 TGT_ORACLE_STG: The connector connected to Oracle server PBWODS.
8:33:35 PM 12/16/2013 TGT_ORACLE_STG: The connector will run in parallel on 2 processing nodes.
9:05:24 PM 12/16/2013 main_program: APT configuration file: /fods/BW/PRD/dsg/IBM/InformationServer/Server/Configurations/default.apt
9:05:26 PM 12/16/2013 TGT_ORACLE_STG: The connector ran the specified Before SQL statement.

prasson_ibm · Post by **prasson_ibm** » Tue Dec 17, 2013 1:49 am

Hi,
Just remove before sql statement and check the job log.Generally it takes 2-3 seconds to run config file,so my guess is its your before sql statement(may be) taking time.

austin_316 · Post by **austin_316** » Tue Dec 17, 2013 2:02 am

I can try removing the before SQL statement. But when we see the logs the Before SQL statment log is being shown only after 2secs.
Is it that before showing the config file log, the Before SQL statement is executed?
Also there are only 7000 records in the table and an Index also is defined on the key columns. So I was assuming it is not because of the Before SQL statement.

IBM Analytics Champion 2009 - 2020 · Post by **asorrell** » Tue Dec 17, 2013 9:31 am

Try executing the Before SQL manually to verify that it takes 40 minutes.

austin_316 · Post by **austin_316** » Mon May 11, 2015 12:49 am

The issue was indeed because of the Before SQL statement.
Thanks everyone for the help

PaulVL · Post by **PaulVL** » Mon May 11, 2015 8:26 am

It's important to remember that the timestamps in the log file are NOT the time where the activity happened, they are the time entries when the activity was LOGGED.

Sometimes the LOG PRINTING doesn't flush until the next log print statement is sent.