AnsweredAssumed Answered

Periodic failures of Pentaho jobs

Question asked by Matthew Peddle on Jul 5, 2018
Latest reply on Jul 6, 2018 by Dan Keeley


I have a pretty simple system copying data from an MSSQL database to a MySQL database that has erratic errors without useful error text. 

 

In other words, sometimes my jobs run.  Other times, they finish in only a couple of minutes without an error.  Here's an example of the second case.  Any ideas?

 

 

/home/ubuntu

2018/07/02 07:20:27 - Kitchen - Logging is at level : Debugging

2018/07/02 07:20:27 - Kitchen - Start of run.

2018/07/02 07:20:27 - Kitchen - Allocate new job.

2018/07/02 07:20:29 - Kitchen - Parsing command line options.

2018/07/02 07:20:45 - Stage1-AltPricingTables - Start of job execution

2018/07/02 07:20:45 - Stage1-AltPricingTables - exec(0, 0, START.0)

2018/07/02 07:20:45 - START - Starting job entry

2018/07/02 07:20:45 - Stage1-AltPricingTables - Starting entry [Copy data to [RMRENTS]]

2018/07/02 07:20:45 - Stage1-AltPricingTables - exec(1, 0, Copy data to [RMRENTS].0)

2018/07/02 07:20:45 - Copy data to [RMRENTS] - Starting job entry

2018/07/02 07:20:45 - Copy data to [RMRENTS] - Opening transformation: [file:///home/ubuntu/dwh_batch/interfaces/PentahoScripts/copy_srmrents_to_m.ktr]

2018/07/02 07:20:45 - Copy data to [RMRENTS] - Loading transformation from XML file [file:///home/ubuntu/dwh_batch/interfaces/PentahoScripts/copy_srmrents_to_m.ktr]

2018/07/02 07:20:49 - Copy data to [RMRENTS] - Starting transformation...(file=${Internal.Job.Filename.Directory}/copy_srmrents_to_m.ktr, name=Copy data to [RMRENTS], repinfo=This job entry executes the transformation to copy data

2018/07/02 07:20:49 - Copy data to [RMRENTS] - from: [S].[RMRENTS]

2018/07/02 07:20:49 - Copy data to [RMRENTS] - to:   [M].[RMRENTS])

2018/07/02 07:20:49 - copy_srmrents_to_m - Transformation is pre-loaded.

2018/07/02 07:20:49 - copy_srmrents_to_m - nr of steps to run : 2  , nr of hops : 1

2018/07/02 07:20:49 - copy_srmrents_to_m - Dispatching started for transformation [copy_srmrents_to_m]

2018/07/02 07:20:49 - copy_srmrents_to_m - Nr of arguments detected:0

2018/07/02 07:20:49 - copy_srmrents_to_m - This is not a replay transformation

2018/07/02 07:20:49 - copy_srmrents_to_m - I found 2 different steps to launch.

2018/07/02 07:20:49 - copy_srmrents_to_m - Allocating rowsets...

2018/07/02 07:20:49 - copy_srmrents_to_m -  Allocating rowsets for step 0 --> read from [RMRENTS]

2018/07/02 07:20:49 - copy_srmrents_to_m -   prevcopies = 1, nextcopies=1

2018/07/02 07:20:50 - copy_srmrents_to_m - Transformation allocated new rowset [read from [RMRENTS].0 - write to [RMRENTS].0]

2018/07/02 07:20:50 - copy_srmrents_to_m -  Allocated 1 rowsets for step 0 --> read from [RMRENTS]

2018/07/02 07:20:50 - copy_srmrents_to_m -  Allocating rowsets for step 1 --> write to [RMRENTS]

2018/07/02 07:20:50 - copy_srmrents_to_m -  Allocated 1 rowsets for step 1 --> write to [RMRENTS]

2018/07/02 07:20:50 - copy_srmrents_to_m - Allocating Steps & StepData...

2018/07/02 07:20:50 - copy_srmrents_to_m -  Transformation is about to allocate step [read from [RMRENTS]] of type [TableInput]

2018/07/02 07:20:50 - copy_srmrents_to_m -   Step has nrcopies=1

2018/07/02 07:20:50 - read from [RMRENTS].0 - distribution activated

2018/07/02 07:20:50 - read from [RMRENTS].0 - Starting allocation of buffers & new threads...

2018/07/02 07:20:50 - read from [RMRENTS].0 - Step info: nrinput=0 nroutput=1

2018/07/02 07:20:50 - read from [RMRENTS].0 - output rel. is  1:1

2018/07/02 07:20:50 - read from [RMRENTS].0 - Found output rowset [read from [RMRENTS].0 - write to [RMRENTS].0]

2018/07/02 07:20:50 - read from [RMRENTS].0 - Finished dispatching

2018/07/02 07:20:50 - copy_srmrents_to_m -  Transformation has allocated a new step: [read from [RMRENTS]].0

2018/07/02 07:20:50 - copy_srmrents_to_m -  Transformation is about to allocate step [write to [RMRENTS]] of type [TableOutput]

2018/07/02 07:20:50 - copy_srmrents_to_m -   Step has nrcopies=1

2018/07/02 07:20:50 - write to [RMRENTS].0 - distribution activated

2018/07/02 07:20:50 - write to [RMRENTS].0 - Starting allocation of buffers & new threads...

2018/07/02 07:20:50 - write to [RMRENTS].0 - Step info: nrinput=1 nroutput=0

2018/07/02 07:20:50 - write to [RMRENTS].0 - Got previous step from [write to [RMRENTS]] #0 --> read from [RMRENTS]

2018/07/02 07:20:50 - write to [RMRENTS].0 - input rel is 1:1

2018/07/02 07:20:50 - write to [RMRENTS].0 - Found input rowset [read from [RMRENTS].0 - write to [RMRENTS].0]

2018/07/02 07:20:50 - write to [RMRENTS].0 - Finished dispatching

2018/07/02 07:20:50 - copy_srmrents_to_m -  Transformation has allocated a new step: [write to [RMRENTS]].0

2018/07/02 07:20:50 - copy_srmrents_to_m - This transformation can be replayed with replay date: 2018/07/02 07:20:50

2018/07/02 07:20:50 - copy_srmrents_to_m - Initialising 2 steps...

2018/07/02 07:20:50 - read from [RMRENTS].0 - Released server socket on port 0

2018/07/02 07:20:50 - write to [RMRENTS].0 - Released server socket on port 0

2018/07/02 07:20:51 - MySQL - MRI 4.5 Production - New database connection defined

2018/07/02 07:20:51 - SQL Server - MRI 4.5 Production - New database connection defined

2018/07/02 07:21:01 - SQL Server - MRI 4.5 Production - Statement canceled!

2018/07/02 07:21:01 - SQL Server - MRI 4.5 Production - Statement canceled!

2018/07/02 07:21:13 - MySQL - MRI 4.5 Production - Connected to database.

2018/07/02 07:21:13 - write to [RMRENTS].0 - Connected to database [MySQL - MRI 4.5 Production] (commit=100000)

2018/07/02 07:21:13 - MySQL - MRI 4.5 Production - Auto commit off

2018/07/02 07:23:24 - copy_srmrents_to_m - Step [write to [RMRENTS].0] initialized flawlessly.

2018/07/02 07:23:24 - read from [RMRENTS].0 - Finished reading query, closing connection.

2018/07/02 07:23:24 - write to [RMRENTS].0 - Signaling 'output done' to 0 output rowsets.

2018/07/02 07:23:24 - MySQL - MRI 4.5 Production - Commit on database connection [MySQL - MRI 4.5 Production]

2018/07/02 07:23:24 - MySQL - MRI 4.5 Production - Connection to database closed!

2018/07/02 07:23:24 - Stage1-AltPricingTables - Finished job entry [Copy data to [RMRENTS]] (result=[false])

2018/07/02 07:23:24 - Stage1-AltPricingTables - Job execution finished

2018/07/02 07:23:24 - Kitchen - Finished!

2018/07/02 07:23:24 - Kitchen - Start=2018/07/02 07:20:27.995, Stop=2018/07/02 07:23:24.610

2018/07/02 07:23:24 - Kitchen - Processing ended after 2 minutes and 56 seconds (176 seconds total).

Outcomes