Uploaded image for project: 'Pentaho Data Integration - Kettle'
  1. Pentaho Data Integration - Kettle
  2. PDI-19354

Table input step is not logging the proper steps in the logs as it used to do before

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Open
    • Severity: Urgent
    • Resolution: Unresolved
    • Affects Version/s: 9.2.0 GA
    • Fix Version/s: Backlog
    • Component/s: Logging, Step
    • Labels:
      None
    • Story Points:
      0
    • PDI Sub-component:
    • Notice:
      When an issue is open, the "Fix Version/s" field conveys a target, not necessarily a commitment. When an issue is closed, the "Fix Version/s" field conveys the version that the issue was fixed in.
    • Sprint Team:
      Tatooine (Maint)
    • Steps to Reproduce:
      Hide

      MySQL Setup

      1. Make sure to have a Foodmart DB
      2. Collect MySQL JDBC Driver 5.1.49 or lower

      Spoon 8.3

      1. Drop MySQL jdbc driver into data-integration/lib
      2. Open the attached transformation: table_input_step_logging.ktr
      3. Make sure to change the DB connection details on the database connection
      4. Run the transformation on Basic, Debug, Detailed and Row Level debug modes and notice the logging information displayed

      Spoon 9.2

      1. Drop MySQL jdbc driver into data-integration/lib
      2. Open the attached transformation: table_input_step_logging.ktr
      3. Make sure to change the DB connection details on the database connection
      4. Run the transformation on Basic, Debug, Detailed and Row Level debug modes and notice the logging information displayed
      Show
      MySQL Setup Make sure to have a Foodmart DB Collect MySQL JDBC Driver 5.1.49 or lower Spoon 8.3 Drop MySQL jdbc driver into data-integration/lib Open the attached transformation: table_input_step_logging.ktr Make sure to change the DB connection details on the database connection Run the transformation on Basic, Debug, Detailed and Row Level debug modes and notice the logging information displayed Spoon 9.2 Drop MySQL jdbc driver into data-integration/lib Open the attached transformation: table_input_step_logging.ktr Make sure to change the DB connection details on the database connection Run the transformation on Basic, Debug, Detailed and Row Level debug modes and notice the logging information displayed

      Description

      Table input step is not logging the proper steps in the logs as it used to do before:
      These are the sample and changes shown in 9.2. We do have this issue when using 8.3.0.15/8.3.0.16 SP as well( we do not see the SQL in the kitchen log as well as in the spoon log. But on the latest SP on 8.3.0.25 we can see the SQL in the logs.
      9.2 Basic Mode

      2021/10/25 09:53:14 - Spoon - Running transformation using the Kettle execution engine
      2021/10/25 09:53:14 - Spoon - Transformation opened.
      2021/10/25 09:53:14 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:53:14 - Spoon - Started the transformation execution.
      2021/10/25 09:53:14 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:53:14 - Table input.0 - !TableInput.Log.FinishedReadingQuery!
      2021/10/25 09:53:14 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:53:14 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:53:14 - Spoon - The transformation has finished!!
      

      9.2 Detailed mode

      2021/10/25 09:53:34 - Spoon - Running transformation using the Kettle execution engine
      2021/10/25 09:53:34 - table_input_step_logging - Transformation is pre-loaded.
      2021/10/25 09:53:34 - Spoon - Transformation opened.
      2021/10/25 09:53:34 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:53:34 - Spoon - Started the transformation execution.
      2021/10/25 09:53:35 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:53:35 - table_input_step_logging - Nr of arguments detected:0
      2021/10/25 09:53:35 - table_input_step_logging - This is not a replay transformation
      2021/10/25 09:53:35 - table_input_step_logging - I found 2 different steps to launch.
      2021/10/25 09:53:35 - table_input_step_logging - Allocating rowsets...
      2021/10/25 09:53:35 - table_input_step_logging -  Allocating rowsets for step 0 --> Table input
      2021/10/25 09:53:35 - table_input_step_logging -   prevcopies = 1, nextcopies=1
      2021/10/25 09:53:35 - table_input_step_logging - Transformation allocated new rowset [Table input.0 - Write to log.0]
      2021/10/25 09:53:35 - table_input_step_logging -  Allocated 1 rowsets for step 0 --> Table input
      2021/10/25 09:53:35 - table_input_step_logging -  Allocating rowsets for step 1 --> Write to log
      2021/10/25 09:53:35 - table_input_step_logging -  Allocated 1 rowsets for step 1 --> Write to log
      2021/10/25 09:53:35 - table_input_step_logging - Allocating Steps & StepData...
      2021/10/25 09:53:35 - table_input_step_logging -  Transformation is about to allocate step [Table input] of type [TableInput]
      2021/10/25 09:53:35 - Table input.0 - distribution activated
      2021/10/25 09:53:35 - Table input.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:53:35 - Table input.0 - Step info: nrinput=0 nroutput=1
      2021/10/25 09:53:35 - Table input.0 - output rel. is  1:1
      2021/10/25 09:53:35 - Table input.0 - Found output rowset [Table input.0 - Write to log.0]
      2021/10/25 09:53:35 - Table input.0 - Finished dispatching
      2021/10/25 09:53:35 - table_input_step_logging -  Transformation has allocated a new step: [Table input].0
      2021/10/25 09:53:35 - table_input_step_logging -  Transformation is about to allocate step [Write to log] of type [WriteToLog]
      2021/10/25 09:53:35 - Write to log.0 - distribution activated
      2021/10/25 09:53:35 - Write to log.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:53:35 - Write to log.0 - Step info: nrinput=1 nroutput=0
      2021/10/25 09:53:35 - Write to log.0 - Got previous step from [Write to log] #0 --> Table input
      2021/10/25 09:53:35 - Write to log.0 - input rel is 1:1
      2021/10/25 09:53:35 - Write to log.0 - Found input rowset [Table input.0 - Write to log.0]
      2021/10/25 09:53:35 - Write to log.0 - Finished dispatching
      2021/10/25 09:53:35 - table_input_step_logging -  Transformation has allocated a new step: [Write to log].0
      2021/10/25 09:53:35 - table_input_step_logging - This transformation can be replayed with replay date: 2021/10/25 09:53:35
      2021/10/25 09:53:35 - table_input_step_logging - Initialising 2 steps...
      2021/10/25 09:53:35 - Table input.0 - Released server socket on port 0
      2021/10/25 09:53:35 - test - New database connection defined
      2021/10/25 09:53:35 - Write to log.0 - Released server socket on port 0
      2021/10/25 09:53:35 - Table input.0 - !TableInput.Log.ConnectedToDatabase!
      2021/10/25 09:53:35 - table_input_step_logging - Step [Table input.0] initialized flawlessly.
      2021/10/25 09:53:35 - table_input_step_logging - Step [Write to log.0] initialized flawlessly.
      2021/10/25 09:53:35 - Table input.0 - Starting to run...
      2021/10/25 09:53:35 - Write to log.0 - Starting to run...
      2021/10/25 09:53:35 - table_input_step_logging - Transformation has allocated 2 threads and 1 rowsets.
      2021/10/25 09:53:35 - Table input.0 - !TableInput.Log.SqlQuery!
      2021/10/25 09:53:35 - Table input.0 - !TableInput.Log.FinishedReadingQuery!
      2021/10/25 09:53:35 - test - Connection to database closed!
      2021/10/25 09:53:35 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:53:35 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:53:35 - Spoon - The transformation has finished!!
      

      9.2 Debug mode

      2021/10/25 09:55:37 - Spoon - Running transformation using the Kettle execution engine
      2021/10/25 09:55:37 - General - We have 1 connections...
      2021/10/25 09:55:37 - General - Looking at connection #0
      2021/10/25 09:55:37 - General - Reading 2 steps...
      2021/10/25 09:55:37 - General - Looking at step #0
      2021/10/25 09:55:37 - General - Looking at step #1
      2021/10/25 09:55:37 - General - We have 1 hops...
      2021/10/25 09:55:37 - General - Looking at hop #0
      2021/10/25 09:55:37 - General - nr of steps read : 2
      2021/10/25 09:55:37 - General - nr of hops  read : 1
      2021/10/25 09:55:37 - table_input_step_logging - Transformation is pre-loaded.
      2021/10/25 09:55:37 - table_input_step_logging - nr of steps to run : 2  , nr of hops : 1
      2021/10/25 09:55:37 - Spoon - Transformation opened.
      2021/10/25 09:55:37 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:55:37 - Spoon - Started the transformation execution.
      2021/10/25 09:55:37 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:55:37 - table_input_step_logging - Nr of arguments detected:0
      2021/10/25 09:55:37 - table_input_step_logging - This is not a replay transformation
      2021/10/25 09:55:37 - table_input_step_logging - I found 2 different steps to launch.
      2021/10/25 09:55:37 - table_input_step_logging - Allocating rowsets...
      2021/10/25 09:55:37 - table_input_step_logging -  Allocating rowsets for step 0 --> Table input
      2021/10/25 09:55:37 - table_input_step_logging -   prevcopies = 1, nextcopies=1
      2021/10/25 09:55:37 - table_input_step_logging - Transformation allocated new rowset [Table input.0 - Write to log.0]
      2021/10/25 09:55:37 - table_input_step_logging -  Allocated 1 rowsets for step 0 --> Table input
      2021/10/25 09:55:37 - table_input_step_logging -  Allocating rowsets for step 1 --> Write to log
      2021/10/25 09:55:37 - table_input_step_logging -  Allocated 1 rowsets for step 1 --> Write to log
      2021/10/25 09:55:37 - table_input_step_logging - Allocating Steps & StepData...
      2021/10/25 09:55:37 - table_input_step_logging -  Transformation is about to allocate step [Table input] of type [TableInput]
      2021/10/25 09:55:37 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 09:55:37 - Table input.0 - distribution activated
      2021/10/25 09:55:37 - Table input.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:55:37 - Table input.0 - Step info: nrinput=0 nroutput=1
      2021/10/25 09:55:37 - Table input.0 - output rel. is  1:1
      2021/10/25 09:55:37 - Table input.0 - Found output rowset [Table input.0 - Write to log.0]
      2021/10/25 09:55:37 - Table input.0 - Finished dispatching
      2021/10/25 09:55:37 - table_input_step_logging -  Transformation has allocated a new step: [Table input].0
      2021/10/25 09:55:37 - table_input_step_logging -  Transformation is about to allocate step [Write to log] of type [WriteToLog]
      2021/10/25 09:55:37 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 09:55:37 - Write to log.0 - distribution activated
      2021/10/25 09:55:37 - Write to log.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:55:37 - Write to log.0 - Step info: nrinput=1 nroutput=0
      2021/10/25 09:55:37 - Write to log.0 - Got previous step from [Write to log] #0 --> Table input
      2021/10/25 09:55:37 - Write to log.0 - input rel is 1:1
      2021/10/25 09:55:37 - Write to log.0 - Found input rowset [Table input.0 - Write to log.0]
      2021/10/25 09:55:37 - Write to log.0 - Finished dispatching
      2021/10/25 09:55:37 - table_input_step_logging -  Transformation has allocated a new step: [Write to log].0
      2021/10/25 09:55:37 - table_input_step_logging - This transformation can be replayed with replay date: 2021/10/25 09:55:37
      2021/10/25 09:55:37 - table_input_step_logging - Initialising 2 steps...
      2021/10/25 09:55:37 - Table input.0 - Released server socket on port 0
      2021/10/25 09:55:37 - Write to log.0 - Released server socket on port 0
      2021/10/25 09:55:37 - test - New database connection defined
      2021/10/25 09:55:37 - Table input.0 - !TableInput.Log.ConnectedToDatabase!
      2021/10/25 09:55:37 - table_input_step_logging - Step [Table input.0] initialized flawlessly.
      2021/10/25 09:55:37 - table_input_step_logging - Step [Write to log.0] initialized flawlessly.
      2021/10/25 09:55:37 - General - From step: Table input, looking at 0 prev. steps.
      2021/10/25 09:55:37 - General - Getting fields from step: Table input, type=TableInput
      2021/10/25 09:55:37 - General - From step: Write to log, looking at 1 prev. steps.
      2021/10/25 09:55:37 - General - From step: Table input, looking at 0 prev. steps.
      2021/10/25 09:55:37 - General - Getting fields from step: Table input, type=TableInput
      2021/10/25 09:55:37 - General - Found fields to add: [employee_id Integer(9)], [full_name String(30)], [first_name String(30)], [last_name String(30)], [position_id Integer(9)], [position_title String(30)], [store_id Integer(9)], [department_id Integer(9)], [birth_date Date], [hire_date Timestamp], [end_date Timestamp], [salary Number(10, 4)], [supervisor_id Integer(9)], [education_level String(30)], [marital_status String(30)], [gender String(30)], [management_role String(30)]
      2021/10/25 09:55:37 - General - Getting fields from step: Write to log, type=WriteToLog
      2021/10/25 09:55:37 - Table input.0 - Starting to run...
      2021/10/25 09:55:37 - Write to log.0 - Starting to run...
      2021/10/25 09:55:37 - table_input_step_logging - Transformation has allocated 2 threads and 1 rowsets.
      2021/10/25 09:55:37 - Table input.0 - !TableInput.Log.SqlQuery!
      2021/10/25 09:55:37 - Table input.0 - Signaling 'output done' to 1 output rowsets.
      2021/10/25 09:55:37 - Table input.0 - !TableInput.Log.FinishedReadingQuery!
      2021/10/25 09:55:37 - test - Connection to database closed!
      2021/10/25 09:55:37 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:55:37 - Write to log.0 - Signaling 'output done' to 0 output rowsets.
      2021/10/25 09:55:37 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:55:37 - table_input_step_logging - searching for annotations
      2021/10/25 09:55:37 - table_input_step_logging - no annotations found
      2021/10/25 09:55:37 - General - Size of ServiceMap:  2
      2021/10/25 09:55:37 - General - Size of ServiceMap:  3
      2021/10/25 09:55:37 - General - Size of ServiceMap:  3
      2021/10/25 09:55:37 - Spoon - The transformation has finished!!
      2021/10/25 09:55:39 - General - LoggingRegistry Stats:
      2021/10/25 09:55:39 - General -     FoundCount= 67 | MapSize= 63 | PurgeCount= 5 | PurgeObjectCount= 0
      

      9.2 Row Level Detailed

      2021/10/25 10:13:02 - Spoon - Running transformation using the Kettle execution engine
      2021/10/25 10:13:02 - General - We have 1 connections...
      2021/10/25 10:13:02 - General - Looking at connection #0
      2021/10/25 10:13:02 - General - Reading 2 steps...
      2021/10/25 10:13:02 - General - Looking at step #0
      2021/10/25 10:13:02 - General - Looking at step #1
      2021/10/25 10:13:02 - General - We have 1 hops...
      2021/10/25 10:13:02 - General - Looking at hop #0
      2021/10/25 10:13:02 - General - nr of steps read : 2
      2021/10/25 10:13:02 - General - nr of hops  read : 1
      2021/10/25 10:13:02 - table_input_step_logging - Transformation is pre-loaded.
      2021/10/25 10:13:02 - table_input_step_logging - nr of steps to run : 2  , nr of hops : 1
      2021/10/25 10:13:02 - Spoon - Transformation opened.
      2021/10/25 10:13:02 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 10:13:02 - Spoon - Started the transformation execution.
      2021/10/25 10:13:02 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 10:13:02 - table_input_step_logging - Nr of arguments detected:0 
      2021/10/25 10:13:02 - table_input_step_logging - This is not a replay transformation
      2021/10/25 10:13:02 - table_input_step_logging - I found 2 different steps to launch.
      2021/10/25 10:13:02 - table_input_step_logging - Allocating rowsets...
      2021/10/25 10:13:02 - table_input_step_logging -  Allocating rowsets for step 0 --> Table input
      2021/10/25 10:13:02 - table_input_step_logging -   prevcopies = 1, nextcopies=1
      2021/10/25 10:13:02 - table_input_step_logging - Transformation allocated new rowset [Table input.0 - Write to log.0]
      2021/10/25 10:13:02 - table_input_step_logging -  Allocated 1 rowsets for step 0 --> Table input  
      2021/10/25 10:13:02 - table_input_step_logging -  Allocating rowsets for step 1 --> Write to log
      2021/10/25 10:13:02 - table_input_step_logging -  Allocated 1 rowsets for step 1 --> Write to log  
      2021/10/25 10:13:02 - table_input_step_logging - Allocating Steps & StepData...
      2021/10/25 10:13:02 - table_input_step_logging -  Transformation is about to allocate step [Table input] of type [TableInput]
      2021/10/25 10:13:02 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 10:13:02 - Table input.0 - distribution activated
      2021/10/25 10:13:02 - Table input.0 - Starting allocation of buffers & new threads...
      2021/10/25 10:13:02 - Table input.0 - Step info: nrinput=0 nroutput=1
      2021/10/25 10:13:02 - Table input.0 - output rel. is  1:1
      2021/10/25 10:13:02 - Table input.0 - Found output rowset [Table input.0 - Write to log.0]
      2021/10/25 10:13:02 - Table input.0 - Finished dispatching
      2021/10/25 10:13:02 - table_input_step_logging -  Transformation has allocated a new step: [Table input].0
      2021/10/25 10:13:02 - table_input_step_logging -  Transformation is about to allocate step [Write to log] of type [WriteToLog]
      2021/10/25 10:13:02 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 10:13:02 - Write to log.0 - distribution activated
      2021/10/25 10:13:02 - Write to log.0 - Starting allocation of buffers & new threads...
      2021/10/25 10:13:02 - Write to log.0 - Step info: nrinput=1 nroutput=0
      2021/10/25 10:13:02 - Write to log.0 - Got previous step from [Write to log] #0 --> Table input
      2021/10/25 10:13:02 - Write to log.0 - input rel is 1:1
      2021/10/25 10:13:02 - Write to log.0 - Found input rowset [Table input.0 - Write to log.0]
      2021/10/25 10:13:02 - Write to log.0 - Finished dispatching
      2021/10/25 10:13:02 - table_input_step_logging -  Transformation has allocated a new step: [Write to log].0
      2021/10/25 10:13:02 - table_input_step_logging - This transformation can be replayed with replay date: 2021/10/25 10:13:02
      2021/10/25 10:13:02 - table_input_step_logging - Initialising 2 steps...
      2021/10/25 10:13:02 - Table input.0 - Released server socket on port 0
      2021/10/25 10:13:02 - Write to log.0 - Released server socket on port 0
      2021/10/25 10:13:02 - test - New database connection defined
      Mon Oct 25 10:13:02 CDT 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification.
      2021/10/25 10:13:02 - Table input.0 - !TableInput.Log.ConnectedToDatabase!
      2021/10/25 10:13:02 - table_input_step_logging - Step [Table input.0] initialized flawlessly.
      2021/10/25 10:13:02 - table_input_step_logging - Step [Write to log.0] initialized flawlessly.
      2021/10/25 10:13:02 - General - From step: Table input, looking at 0 prev. steps.
      2021/10/25 10:13:02 - General - Getting fields from step: Table input, type=TableInput
      2021/10/25 10:13:02 - General - From step: Write to log, looking at 1 prev. steps.
      2021/10/25 10:13:02 - General - From step: Table input, looking at 0 prev. steps.
      2021/10/25 10:13:02 - General - Getting fields from step: Table input, type=TableInput
      2021/10/25 10:13:02 - General - Found fields to add: [employee_id Integer(9)], [full_name String(30)], [first_name String(30)], [last_name String(30)], [position_id Integer(9)], [position_title String(30)], [store_id Integer(9)], [department_id Integer(9)], [birth_date Date], [hire_date Timestamp], [end_date Timestamp], [salary Number(10, 4)], [supervisor_id Integer(9)], [education_level String(30)], [marital_status String(30)], [gender String(30)], [management_role String(30)]
      2021/10/25 10:13:02 - General - Getting fields from step: Write to log, type=WriteToLog
      2021/10/25 10:13:02 - Table input.0 - Starting to run...
      2021/10/25 10:13:02 - Write to log.0 - Starting to run...
      2021/10/25 10:13:02 - table_input_step_logging - Transformation has allocated 2 threads and 1 rowsets.
      2021/10/25 10:13:02 - Table input.0 - !TableInput.Log.SqlQuery!
      2021/10/25 10:13:02 - Write to log.0 - 
      2021/10/25 10:13:02 - Write to log.0 - ------------> Linenr 1------------------------------
      2021/10/25 10:13:02 - Write to log.0 - employee_id = 1
      2021/10/25 10:13:02 - Write to log.0 - full_name = Sheri Nowmer
      2021/10/25 10:13:02 - Write to log.0 - first_name = Sheri
      2021/10/25 10:13:02 - Write to log.0 - last_name = Nowmer
      2021/10/25 10:13:02 - Write to log.0 - position_id = 1
      2021/10/25 10:13:02 - Write to log.0 - position_title = President
      2021/10/25 10:13:02 - Write to log.0 - store_id = 0
      2021/10/25 10:13:02 - Write to log.0 - department_id = 1
      2021/10/25 10:13:02 - Write to log.0 - birth_date = 1961/08/26 00:00:00.000
      2021/10/25 10:13:02 - Write to log.0 - hire_date = 1994/12/01 00:00:00.000000000
      2021/10/25 10:13:02 - Write to log.0 - end_date = null
      2021/10/25 10:13:02 - Write to log.0 - salary = 80000.0
      2021/10/25 10:13:02 - Write to log.0 - supervisor_id = 0
      2021/10/25 10:13:02 - Write to log.0 - education_level = Graduate Degree
      2021/10/25 10:13:02 - Write to log.0 - marital_status = S
      2021/10/25 10:13:02 - Write to log.0 - gender = F
      2021/10/25 10:13:02 - Write to log.0 - management_role = Senior Management
      2021/10/25 10:13:02 - Write to log.0 - 
      2021/10/25 10:13:02 - Write to log.0 - ====================
      2021/10/25 10:13:02 - Write to log.0 - 
      

      This is how it was showing before 9.2
      8.3 Basic Mode

      2021/10/25 09:47:21 - Spoon - Using legacy execution engine
      2021/10/25 09:47:21 - Spoon - Transformation opened.
      2021/10/25 09:47:21 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:47:21 - Spoon - Started the transformation execution.
      2021/10/25 09:47:21 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:47:21 - Table input.0 - Finished reading query, closing connection.
      2021/10/25 09:47:21 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:47:21 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:47:21 - Spoon - The transformation has finished!!
      

      8.3 Detailed Mode

      2021/10/25 09:47:50 - Spoon - Using legacy execution engine
      2021/10/25 09:47:50 - table_input_step_logging - Transformation is pre-loaded.
      2021/10/25 09:47:50 - Spoon - Transformation opened.
      2021/10/25 09:47:50 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:47:50 - Spoon - Started the transformation execution.
      2021/10/25 09:47:50 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:47:50 - table_input_step_logging - Nr of arguments detected:0
      2021/10/25 09:47:50 - table_input_step_logging - This is not a replay transformation
      2021/10/25 09:47:50 - table_input_step_logging - I found 2 different steps to launch.
      2021/10/25 09:47:50 - table_input_step_logging - Allocating rowsets...
      2021/10/25 09:47:50 - table_input_step_logging -  Allocating rowsets for step 0 --> Table input
      2021/10/25 09:47:50 - table_input_step_logging -   prevcopies = 1, nextcopies=1
      2021/10/25 09:47:50 - table_input_step_logging - Transformation allocated new rowset [Table input.0 - Write to log.0]
      2021/10/25 09:47:50 - table_input_step_logging -  Allocated 1 rowsets for step 0 --> Table input
      2021/10/25 09:47:50 - table_input_step_logging -  Allocating rowsets for step 1 --> Write to log
      2021/10/25 09:47:50 - table_input_step_logging -  Allocated 1 rowsets for step 1 --> Write to log
      2021/10/25 09:47:50 - table_input_step_logging - Allocating Steps & StepData...
      2021/10/25 09:47:50 - table_input_step_logging -  Transformation is about to allocate step [Table input] of type [TableInput]
      2021/10/25 09:47:50 - Table input.0 - distribution activated
      2021/10/25 09:47:50 - Table input.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:47:50 - Table input.0 - Step info: nrinput=0 nroutput=1
      2021/10/25 09:47:50 - Table input.0 - output rel. is  1:1
      2021/10/25 09:47:50 - Table input.0 - Found output rowset [Table input.0 - Write to log.0]
      2021/10/25 09:47:50 - Table input.0 - Finished dispatching
      2021/10/25 09:47:50 - table_input_step_logging -  Transformation has allocated a new step: [Table input].0
      2021/10/25 09:47:50 - table_input_step_logging -  Transformation is about to allocate step [Write to log] of type [WriteToLog]
      2021/10/25 09:47:50 - Write to log.0 - distribution activated
      2021/10/25 09:47:50 - Write to log.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:47:50 - Write to log.0 - Step info: nrinput=1 nroutput=0
      2021/10/25 09:47:50 - Write to log.0 - Got previous step from [Write to log] #0 --> Table input
      2021/10/25 09:47:50 - Write to log.0 - input rel is 1:1
      2021/10/25 09:47:50 - Write to log.0 - Found input rowset [Table input.0 - Write to log.0]
      2021/10/25 09:47:50 - Write to log.0 - Finished dispatching
      2021/10/25 09:47:50 - table_input_step_logging -  Transformation has allocated a new step: [Write to log].0
      2021/10/25 09:47:50 - table_input_step_logging - This transformation can be replayed with replay date: 2021/10/25 09:47:50
      2021/10/25 09:47:50 - table_input_step_logging - Initialising 2 steps...
      2021/10/25 09:47:50 - Table input.0 - Released server socket on port 0
      2021/10/25 09:47:50 - Write to log.0 - Released server socket on port 0
      2021/10/25 09:47:50 - test - New database connection defined
      2021/10/25 09:47:50 - Table input.0 - Connected to database...
      2021/10/25 09:47:50 - table_input_step_logging - Step [Table input.0] initialized flawlessly.
      2021/10/25 09:47:50 - table_input_step_logging - Step [Write to log.0] initialized flawlessly.
      2021/10/25 09:47:50 - Table input.0 - Starting to run...
      2021/10/25 09:47:50 - Write to log.0 - Starting to run...
      2021/10/25 09:47:50 - table_input_step_logging - Transformation has allocated 2 threads and 1 rowsets.
      2021/10/25 09:47:50 - Table input.0 - SQL query : SELECT
        employee_id
      , full_name
      , first_name
      , last_name
      , position_id
      , position_title
      , store_id
      , department_id
      , birth_date
      , hire_date
      , end_date
      , salary
      , supervisor_id
      , education_level
      , marital_status
      , gender
      , management_role
      FROM employee
      2021/10/25 09:47:50 - Table input.0 - Finished reading query, closing connection.
      2021/10/25 09:47:50 - test - Connection to database closed!
      2021/10/25 09:47:50 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:47:50 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:47:50 - Spoon - The transformation has finished!!
      

      8.3 Debug mode:

      2021/10/25 09:48:43 - Spoon - Using legacy execution engine
      2021/10/25 09:48:43 - table_input_step_logging - Transformation is pre-loaded.
      2021/10/25 09:48:43 - table_input_step_logging - nr of steps to run : 2  , nr of hops : 1
      2021/10/25 09:48:43 - Spoon - Transformation opened.
      2021/10/25 09:48:43 - Spoon - Launching transformation [table_input_step_logging]...
      2021/10/25 09:48:43 - Spoon - Started the transformation execution.
      2021/10/25 09:48:43 - table_input_step_logging - Dispatching started for transformation [table_input_step_logging]
      2021/10/25 09:48:43 - table_input_step_logging - Nr of arguments detected:0
      2021/10/25 09:48:43 - table_input_step_logging - This is not a replay transformation
      2021/10/25 09:48:43 - table_input_step_logging - I found 2 different steps to launch.
      2021/10/25 09:48:43 - table_input_step_logging - Allocating rowsets...
      2021/10/25 09:48:43 - table_input_step_logging -  Allocating rowsets for step 0 --> Table input
      2021/10/25 09:48:43 - table_input_step_logging -   prevcopies = 1, nextcopies=1
      2021/10/25 09:48:43 - table_input_step_logging - Transformation allocated new rowset [Table input.0 - Write to log.0]
      2021/10/25 09:48:43 - table_input_step_logging -  Allocated 1 rowsets for step 0 --> Table input
      2021/10/25 09:48:43 - table_input_step_logging -  Allocating rowsets for step 1 --> Write to log
      2021/10/25 09:48:43 - table_input_step_logging -  Allocated 1 rowsets for step 1 --> Write to log
      2021/10/25 09:48:43 - table_input_step_logging - Allocating Steps & StepData...
      2021/10/25 09:48:43 - table_input_step_logging -  Transformation is about to allocate step [Table input] of type [TableInput]
      2021/10/25 09:48:43 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 09:48:43 - Table input.0 - distribution activated
      2021/10/25 09:48:43 - Table input.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:48:43 - Table input.0 - Step info: nrinput=0 nroutput=1
      2021/10/25 09:48:43 - Table input.0 - output rel. is  1:1
      2021/10/25 09:48:43 - Table input.0 - Found output rowset [Table input.0 - Write to log.0]
      2021/10/25 09:48:43 - Table input.0 - Finished dispatching
      2021/10/25 09:48:43 - table_input_step_logging -  Transformation has allocated a new step: [Table input].0
      2021/10/25 09:48:43 - table_input_step_logging -  Transformation is about to allocate step [Write to log] of type [WriteToLog]
      2021/10/25 09:48:43 - table_input_step_logging -   Step has nrcopies=1
      2021/10/25 09:48:43 - Write to log.0 - distribution activated
      2021/10/25 09:48:43 - Write to log.0 - Starting allocation of buffers & new threads...
      2021/10/25 09:48:43 - Write to log.0 - Step info: nrinput=1 nroutput=0
      2021/10/25 09:48:43 - Write to log.0 - Got previous step from [Write to log] #0 --> Table input
      2021/10/25 09:48:43 - Write to log.0 - input rel is 1:1
      2021/10/25 09:48:43 - Write to log.0 - Found input rowset [Table input.0 - Write to log.0]
      2021/10/25 09:48:43 - Write to log.0 - Finished dispatching
      2021/10/25 09:48:43 - table_input_step_logging -  Transformation has allocated a new step: [Write to log].0
      2021/10/25 09:48:43 - table_input_step_logging - This transformation can be replayed with replay date: 2021/10/25 09:48:43
      2021/10/25 09:48:43 - table_input_step_logging - Initialising 2 steps...
      2021/10/25 09:48:43 - Table input.0 - Released server socket on port 0
      2021/10/25 09:48:43 - Write to log.0 - Released server socket on port 0
      2021/10/25 09:48:43 - test - New database connection defined
      2021/10/25 09:48:43 - Table input.0 - Connected to database...
      2021/10/25 09:48:43 - table_input_step_logging - Step [Table input.0] initialized flawlessly.
      2021/10/25 09:48:43 - table_input_step_logging - Step [Write to log.0] initialized flawlessly.
      2021/10/25 09:48:43 - Table input.0 - Starting to run...
      2021/10/25 09:48:43 - Write to log.0 - Starting to run...
      2021/10/25 09:48:43 - table_input_step_logging - Transformation has allocated 2 threads and 1 rowsets.
      2021/10/25 09:48:43 - Table input.0 - SQL query : SELECT
        employee_id
      , full_name
      , first_name
      , last_name
      , position_id
      , position_title
      , store_id
      , department_id
      , birth_date
      , hire_date
      , end_date
      , salary
      , supervisor_id
      , education_level
      , marital_status
      , gender
      , management_role
      FROM employee
      2021/10/25 09:48:43 - Table input.0 - Signaling 'output done' to 1 output rowsets.
      2021/10/25 09:48:43 - Table input.0 - Finished reading query, closing connection.
      2021/10/25 09:48:43 - test - Connection to database closed!
      2021/10/25 09:48:43 - Table input.0 - Finished processing (I=1155, O=0, R=0, W=1155, U=0, E=0)
      2021/10/25 09:48:43 - Write to log.0 - Signaling 'output done' to 0 output rowsets.
      2021/10/25 09:48:43 - Write to log.0 - Finished processing (I=0, O=0, R=1155, W=1155, U=0, E=0)
      2021/10/25 09:48:43 - table_input_step_logging - searching for annotations
      2021/10/25 09:48:43 - table_input_step_logging - no annotations found
      2021/10/25 09:48:43 - Spoon - The transformation has finished!!
      

        Attachments

        1. 83_spoon.log
          1.52 MB
        2. 92_spoon.log
          1.54 MB
        3. table_input_step_logging.ktr
          16 kB

          Activity

            People

            Assignee:
            sergio.ribeiro SĂ©rgio Ribeiro
            Reporter:
            jagdeeshss Jagdeeshss
            Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

              Dates

              Created:
              Updated: