Delphix Products

 View Only
Expand all | Collapse all

Unable to disable constraints-Oracle

  • 1.  Unable to disable constraints-Oracle

    Posted 11-10-2022 06:54:00 PM
    Hi Experts,

    I am trying to mask a column (containing first name) but having primary key and Parent-child relationship with other 2 tables & Delphix couldn't able to disable the constraint, here is the error:



    Seems some drive for Oracle is not supported and not allowing disabling constraint.

    so do we've resolution to this or any other option apart from running the pre & post SQL script to disable & enable the constraint & will it work in this case where parent-child relationship is there.

    Looking forward to expert advice & happy to share more details, if required.


    Regards,
    Raman



    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------


  • 2.  RE: Unable to disable constraints-Oracle

    Posted 11-14-2022 10:25:00 PM
    Further to above error, I am getting below error while disabling the constraints via pre-sql script:

    2022-11-15T04:05:15,363Z [pool-5-thread-2] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:05:15,366Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - select-value and SM table input steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:05:15,366Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - SM steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:05:15,366Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: User-defined steps generation finished
    2022-11-15T04:05:15,367Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: Dump-distinct and seq-id in-place steps generation finished
    2022-11-15T04:05:15,367Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: MA-algo table input/output steps generation finished
    2022-11-15T04:05:15,367Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: table-input/ output steps for MA generation finished
    2022-11-15T04:05:15,370Z [pool-5-thread-2] WARN c.d.d.xmlartist.XmlArtist - Step 'SegColSelect values' is not reachable.
    2022-11-15T04:05:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - marshalling of transformation object finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:05:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Finished generating transformation steps for table:MSAH_PER_COV_HIST
    2022-11-15T04:05:15,374Z [pool-5-thread-2] INFO c.d.dmsApplicator.ApplicatorUtil - [JOB_ID_8_201] Saved Job details in job history table
    2022-11-15T04:05:15,382Z [pool-5-thread-2] INFO c.d.d.j.t.JobXMLGenerator - isCreateIdentityColumnFlag:: ::false
    2022-11-15T04:05:15,382Z [pool-5-thread-2] INFO c.d.d.j.t.JobXMLGenerator - logFolder /var/delphix/masking/logs/JobLogs
    2022-11-15T04:05:15,382Z [pool-5-thread-2] INFO c.d.d.j.t.JobXMLGenerator - inner job filePath >>>>>>>>>>>>>>>>>>>>>>>>>>> /var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8
    2022-11-15T04:05:15,386Z [pool-5-thread-2] INFO c.d.d.j.t.JobXMLGenerator - Job 8, Env BOSSPKG, Ruleset bosspkg_new: kettle xml path /var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8
    2022-11-15T04:05:15,387Z [pool-5-thread-2] WARN c.d.d.xmlartist.XmlArtist - Step 'ABORT_JOB_FOR_MA' is not reachable.
    2022-11-15T04:05:15,388Z [pool-5-thread-2] INFO c.d.d.m.t.MaskingMarshalling - Transformation XML completed successfully....
    2022-11-15T04:05:15,388Z [pool-5-thread-2] INFO com.dmsuite.manager.JobManager - prescript query to store in transformation generated successfully.
    2022-11-15T04:05:15,394Z [pool-5-thread-2] INFO com.dmsuite.manager.JobManager - Job and collection 8
    2022-11-15T04:05:15,446Z [pool-5-thread-2] INFO com.dmsuite.manager.JobManager - postscript query to store in transformation generated successfully.
    2022-11-15T04:05:15,454Z [pool-5-thread-2] INFO com.dmsuite.manager.JobManager - Job and collection 8
    2022-11-15T04:05:15,509Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - prescript transformation generate successfully
    2022-11-15T04:05:15,509Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - postscript transformation generate successfully
    2022-11-15T04:05:15,509Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - targetConnector.getInstanceNm():::oracle
    2022-11-15T04:05:15,520Z [pool-5-thread-2] INFO c.d.dmsApplicator.ApplicatorUtil - In Run Command line job
    2022-11-15T04:05:15,521Z [pool-5-thread-2] INFO c.d.dmsApplicator.ApplicatorUtil - OSParamenter :l
    2022-11-15T04:05:15,522Z [pool-5-thread-2] INFO c.d.dmsApplicator.ApplicatorUtil - shCommand :/opt/delphix/masking/DMSApplicator/kitchen.sh /file:/var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8/8.xml -level:Basic
    2022-11-15T04:05:15,525Z [pool-5-thread-2] INFO c.d.dmsApplicator.ApplicatorUtil - JAVA Options: -Xms1024m -Xmx1024m -Xss256m -DMASKING_HOME=/opt/delphix/masking -DMASKING_DATA=/var/delphix/masking -Duser.home=/var/delphix/masking/user_home -DPENTAHO_METASTORE_FOLDER=/var/delphix/masking/DMSApplicator -Djavax.net.ssl.trustStore=/var/delphix/server/etc/.truststore -Djavax.net.ssl.keyStore=/var/delphix/server/etc/.keystore -Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl
    2022-11-15T04:05:15,535Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 0 detected, some features will be unavailable
    2022-11-15T04:05:15,536Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] Consider installing the package with apt-get or yum.
    2022-11-15T04:05:15,536Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] e.g. 'sudo apt-get install libwebkitgtk-1.0-0'
    2022-11-15T04:05:15,536Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] #######################################################################
    2022-11-15T04:05:18,746Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] Invalid entry, ignoring '/opt/delphix/masking/DMSApplicator/launcher/../../../../../var/delphix/masking/resources/jarfiles/db2jcc_license_cisuz.jar'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:16 - General - Plugin class com.masking.MaskingTwoWayPasswordEncoder registered for plugin type 'TwoWayPasswordEncoder'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] Loading security manager
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:16 - Kitchen - Logging is at level : Basic
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:16 - Kitchen - Start of run.
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class com.masking.MaskingTwoWayPasswordEncoder registered for plugin type 'TwoWayPasswordEncoder'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixFileOutputStepMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixTableInsertStepMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixTableUpdateStepMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.customFileInput.plugin.DelphixFileInputStepMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.customFileInput.plugin.DelphixTableInputStepMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class com.dmsuite.kettle.vsaminput.VSAMInputMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class com.dmsuite.kettle.vsamoutput.VSAMOutputMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.StaxCustomInputStep.CustomXMLInputStreamMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class com.delphix.kettle.algorithmStep.AlgorithmStepMetadata registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:17 - General - Plugin class dmsuite.charStreaming.plugin.CharStreamingFileInputMeta registered for plugin type 'Step'
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Start of job execution
    2022-11-15T04:05:18,747Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Starting entry [PRESCRIPT TRANSFORMATION]
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - Loading transformation from XML file [/var/delphix/masking//output/BOSSPKG/DMSApplicator/bosspkg_new/8/KETTLE_PRESCRIPT_TRANSFORMATION_8.xml]
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - Using legacy execution engine
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Prescript_Transformation - Dispatching started for transformation [Prescript_Transformation]
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : An error occurred, processing will be stopped:
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 - Couldn't execute SQL: alter table MSAF_PER_COV disable constraint PK_MSAF_PER_COV
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 -
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 - ORA-02297: cannot disable constraint (BOSSPKG.PK_MSAF_PER_COV) - dependencies exist
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Error initializing step [Execute_Prescript]
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Prescript_Transformation - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Step [Execute_Prescript.0] failed to initialize!
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Execute_Prescript.0 - Finished reading query, closing connection.
    2022-11-15T04:05:18,750Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Unable to prepare for execution of the transformation
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : org.pentaho.di.core.exception.KettleException:
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - We failed to initialize at least one step. Execution can not begin!
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION -
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION -
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.prepareExecution(Trans.java:1157)
    2022-11-15T04:05:18,751Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.execute(Trans.java:627)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.entries.trans.JobEntryTrans.execute(JobEntryTrans.java:1152)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:724)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:865)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:546)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.run(Job.java:436)
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Starting entry [ABORT_JOB_FOR_PRESCRIPT]
    2022-11-15T04:05:18,786Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - ABORT_JOB_FOR_PRESCRIPT - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Job failed, because of Pre-Script execution failure.
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Finished job entry [ABORT_JOB_FOR_PRESCRIPT] (result=[false])
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Finished job entry [PRESCRIPT TRANSFORMATION] (result=[false])
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - 8_201 - Job execution finished
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Kitchen - Finished!
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Kitchen - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Finished with errors
    2022-11-15T04:05:18,791Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Kitchen - Start=2022/11/15 04:05:16.871, Stop=2022/11/15 04:05:18.763
    2022-11-15T04:05:18,792Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] 2022/11/15 04:05:18 - Kitchen - Processing ended after 1 seconds.
    2022-11-15T04:05:18,792Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_201] p.waitFor() is :: 1
    2022-11-15T04:05:18,792Z [pool-5-thread-2] ERROR c.d.d.m.t.RunServiceImpl - Failed to run Kettle without error ::
    com.dmsuite.exception.JobFailedException: Kettle returned a non zero exit value: 1
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1617)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    2022-11-15T04:05:18,796Z [pool-5-thread-2] INFO c.dmsuite.threads.TaskMonitorService - EXECUTIONS mask Task with id 201 deregistered from the monitoring
    2022-11-15T04:05:18,796Z [pool-5-thread-2] INFO c.d.t.ExecutionProgressReporter - Removing execution '201' from being tracked.
    2022-11-15T04:05:18,813Z [pool-5-thread-2] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAH_PER_COV_HIST-c4cabc27-69e5-3d0b-b489-4752a4aa1edf_201'. There was a star log error found for the transformation
    2022-11-15T04:05:18,825Z [pool-5-thread-2] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAF_PER_COV-f00d27ac-b712-31f7-98be-046dd0bae7d4_201'. There was a star log error found for the transformation
    2022-11-15T04:05:18,837Z [pool-5-thread-2] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAG_SURNAME-df65bfe2-07da-35d7-9b35-44bd108c17ce_201'. There was a star log error found for the transformation
    2022-11-15T04:05:18,866Z [pool-5-thread-2] ERROR c.dmsuite.threads.JobExecutorService - [JOB_ID_8_201] - Execution 201 for job 8 failed
    com.dmsuite.exception.JobFailedException: Exception executing job 8:
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1170)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    Caused by: com.dmsuite.exception.JobFailedException: Job has failed due to error in running Kettle
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1635)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    ... 8 common frames omitted
    Caused by: com.dmsuite.exception.JobFailedException: Kettle returned a non zero exit value: 1
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1617)
    ... 9 common frames omitted
    2022-11-15T04:05:18,870Z [pool-5-thread-2] INFO c.d.report.core.UserReportGenerator - jobNm BOSSPKG, displayEnvName BOSSPKG : Generating pdf report for masking
    2022-11-15T04:05:19,044Z [pool-5-thread-2] INFO c.d.report.core.UserReportGenerator - Masking report pdf file path: /var/delphix/masking/reports/masking_201_Tue_Nov_15_040518_UTC_2022.pdf
    2022-11-15T04:05:27,155Z [http-nio-127.0.0.1-8284-exec-10] INFO c.d.common.utils.FileDownloadUtil - Downloading file /var/delphix/masking/logs/JobLogs/8_201.log
    2022-11-15T04:06:03,784Z [http-nio-127.0.0.1-8284-exec-4] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:06:03,867Z [http-nio-127.0.0.1-8284-exec-4] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:06:06,255Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.w.inventory.InventoryController - Inside public ModelAndView view(HttpServletRequest request,HttpServletResponse response,InventoryDTO inventoryDTO)
    2022-11-15T04:06:06,263Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.w.inventory.InventoryController - Connector type table
    2022-11-15T04:06:06,263Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.w.inventory.InventoryController - CollectionName BOSSPKG ALL
    2022-11-15T04:06:06,434Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.w.inventory.InventoryController - getInventoryRowTypes for envId 5, Table name ABD_ENTRY_AGE
    2022-11-15T04:06:10,021Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.inventory.InventoryController - Inside public ModelAndView view(HttpServletRequest request,HttpServletResponse response,InventoryDTO inventoryDTO)
    2022-11-15T04:06:10,029Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.inventory.InventoryController - Connector type table
    2022-11-15T04:06:10,030Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.inventory.InventoryController - CollectionName bosspkg_new
    2022-11-15T04:06:10,160Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.inventory.InventoryController - getInventoryRowTypes for envId 5, Table name MSAF_PER_COV
    2022-11-15T04:06:33,301Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 10875393
    2022-11-15T04:06:33,301Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAF_PER_COV with execution 201 is 10875393
    2022-11-15T04:06:33,375Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAG_SURNAME_SEQ|
    2022-11-15T04:06:33,383Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |6|
    2022-11-15T04:06:33,387Z [Thread-93] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAG_SURNAME: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:06:33,387Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - XF-tableInputSQL: SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:06:33,387Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - fetching total rows for table MSAG_SURNAME with execution 201
    2022-11-15T04:06:33,387Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - ####### connection:oracle.jdbc.driver.T4CConnection@603ce2fc sqlQuery:SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:06:33,387Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - Before calculating count. Query to get count is :: SELECT COUNT(*) FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:06:33,809Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 1887425
    2022-11-15T04:06:33,809Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAG_SURNAME with execution 201 is 1887425
    2022-11-15T04:06:33,843Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_DATE_FROM|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_SCHD_CD|
    2022-11-15T04:06:33,846Z [Thread-93] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:06:33,848Z [Thread-93] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAH_PER_COV_HIST: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:06:33,848Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - XF-tableInputSQL: SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:06:33,848Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - fetching total rows for table MSAH_PER_COV_HIST with execution 201
    2022-11-15T04:06:33,848Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - ####### connection:oracle.jdbc.driver.T4CConnection@603ce2fc sqlQuery:SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:06:33,849Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - Before calculating count. Query to get count is :: SELECT COUNT(*) FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:06:35,441Z [Thread-93] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 6917565
    2022-11-15T04:06:35,441Z [Thread-93] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAH_PER_COV_HIST with execution 201 is 6917565
    2022-11-15T04:06:35,446Z [Thread-93] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAF_PER_COV' in execution '201' with count '10875393'.
    2022-11-15T04:06:35,448Z [Thread-93] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAG_SURNAME' in execution '201' with count '1887425'.
    2022-11-15T04:06:35,449Z [Thread-93] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAH_PER_COV_HIST' in execution '201' with count '6917565'.
    2022-11-15T04:06:35,449Z [Thread-93] INFO c.d.jobs.monitor.MonitorCountThread - Execution '201' in environment 'BOSSPKG': Total table count 3
    Total rows in job 19680383
    2022-11-15T04:09:11,748Z [http-nio-127.0.0.1-8284-exec-5] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:09:11,839Z [http-nio-127.0.0.1-8284-exec-5] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:09:14,387Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.m.a.p.utils.DriverSupportUtil - Successfully loaded driver support class 'class masking.driverSupport.OracleDriverSupport'
    2022-11-15T04:09:14,419Z [http-nio-127.0.0.1-8284-exec-7] INFO c.d.m.a.p.utils.DriverSupportUtil - Successfully loaded driver support class 'class masking.driverSupport.OracleDriverSupport'
    2022-11-15T04:09:17,716Z [http-nio-127.0.0.1-8284-exec-1] INFO c.d.common.utils.FileSystemUtil - Old Pre Script file deletion status :true
    2022-11-15T04:09:36,871Z [http-nio-127.0.0.1-8284-exec-10] INFO c.d.common.utils.FileSystemUtil - Old Pre Script file deletion status :true
    2022-11-15T04:09:36,872Z [http-nio-127.0.0.1-8284-exec-10] INFO c.d.common.utils.FileSystemUtil - Old Pre Script file deletion status :true
    2022-11-15T04:09:39,440Z [http-nio-127.0.0.1-8284-exec-5] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:09:39,525Z [http-nio-127.0.0.1-8284-exec-5] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T04:09:41,582Z [http-nio-127.0.0.1-8284-exec-4] INFO c.d.common.utils.JobExecutionHelper - Launching JOB_ID_8 with job configuration: Job(jobId=8, generatorNm=kettle, generatorConfigNm=kettle_config, preScriptPathTx=test.sql, postScriptPathTx=test1.sql, createTm=2022-05-11 03:21:16.439, jobDescTx=, emails=, onTheFlyFlag=N, reportNm=/var/delphix/masking/reports/masking_201_Tue_Nov_15_040518_UTC_2022.pdf, isConstraintCheck=N, isTruncateCheck=N, environmentJobName=BOSSPKG, paramFileName=null, importMapplet=y, xmx=1024, xms=1024, isTriggerCheck=N, maskNoOfCopies=1, noOfStreams=1, isBulkData=0, feedbackSize=50000, commitSize=10000, isDynamicConnector=0, batchUpdate=1, mapperTaks=0, isProfilerMultipleCheck=0, indexDrop=N, failImmediately=false, transformationRowLimit=20000)
    2022-11-15T04:09:41,682Z [http-nio-127.0.0.1-8284-exec-4] INFO c.dmsuite.threads.JobExecutorService - Job with execution ID: 202 submitted to thread pool
    2022-11-15T04:09:41,682Z [http-nio-127.0.0.1-8284-exec-4] INFO c.d.t.ExecutionProgressReporter - Adding execution '202' to be tracked
    2022-11-15T04:09:41,748Z [pool-5-thread-6] INFO c.dmsuite.threads.TaskMonitorService - EXECUTIONS mask Task with id 202 registered for the monitoring
    2022-11-15T04:09:41,752Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - profilerLogPath ::/var/delphix/masking/logs/JobLogs
    2022-11-15T04:09:41,752Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - logFileName ::8_202.log
    2022-11-15T04:09:41,752Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - logPath::/var/delphix/masking/logs/JobLogs/8_202.log
    2022-11-15T04:09:41,761Z [pool-5-thread-6] INFO c.d.d.masking.XMLGenerator - dbJob.getParamFileName() :- null
    2022-11-15T04:09:41,810Z [pool-5-thread-6] INFO c.d.d.masking.XMLGenerator - finished preparing request xml object.........
    2022-11-15T04:09:41,815Z [pool-5-thread-6] INFO c.d.d.masking.XMLGenerator - Generate request xml started successfully.
    2022-11-15T04:09:41,823Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - Path to Job : /var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8/
    2022-11-15T04:09:41,827Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Generate Transformation XML started successfully
    2022-11-15T04:09:42,078Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8 : Begin generating transformation kettle xml
    2022-11-15T04:09:42,115Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV : Started generating transformation steps
    2022-11-15T04:09:42,115Z [Thread-94] INFO c.d.jobs.monitor.MonitorCountThread - Execution '202': Begin table count
    2022-11-15T04:09:42,121Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV : Finished preparing masking and provisioning columnlists
    2022-11-15T04:09:42,142Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Hop generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,142Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - atLeastOneColFound : true
    2022-11-15T04:09:42,142Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Select value step generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,189Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,195Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |5|
    2022-11-15T04:09:42,199Z [pool-5-thread-6] INFO c.d.d.masking.steps.UpdateImpl - ~~~~~~~~~~~~~~~~~~~~~~ update step :: extension ~~~~~~~~~~~~~~~~
    2022-11-15T04:09:42,199Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## slColList = []
    2022-11-15T04:09:42,199Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## minMaxColList = []
    2022-11-15T04:09:42,221Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,221Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Output steps generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,228Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |5|
    2022-11-15T04:09:42,229Z [Thread-94] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAF_PER_COV: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,229Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - XF-tableInputSQL: SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,229Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - fetching total rows for table MSAF_PER_COV with execution 202
    2022-11-15T04:09:42,229Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - ####### connection:oracle.jdbc.driver.T4CConnection@4a86a892 sqlQuery:SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,229Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - Before calculating count. Query to get count is :: SELECT COUNT(*) FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,265Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,271Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |5|
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAF_PER_COV: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env BOSSPKG, Connector BOSSSNAP_BOSSPKG: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" FROM "BOSSPKG"."MSAF_PER_COV"
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: Lookup and input steps generation finished
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: Get-data-from xml and decrypt steps generation finished
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - XF-generateXML - isInventoryPresent is True.
    2022-11-15T04:09:42,273Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Split-field and constant steps generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,274Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Stream-lkup steps generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,316Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,323Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |5|
    2022-11-15T04:09:42,326Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - select-value and SM table input steps generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,326Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - SM steps generation finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,326Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: User-defined steps generation finished
    2022-11-15T04:09:42,327Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: Dump-distinct and seq-id in-place steps generation finished
    2022-11-15T04:09:42,327Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: MA-algo table input/output steps generation finished
    2022-11-15T04:09:42,327Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAF_PER_COV: table-input/ output steps for MA generation finished
    2022-11-15T04:09:42,330Z [pool-5-thread-6] WARN c.d.d.xmlartist.XmlArtist - Step 'SegColSelect values' is not reachable.
    2022-11-15T04:09:42,331Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - marshalling of transformation object finished for table:MSAF_PER_COV
    2022-11-15T04:09:42,333Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Finished generating transformation steps for table:MSAF_PER_COV
    2022-11-15T04:09:42,333Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME : Started generating transformation steps
    2022-11-15T04:09:42,335Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME : Finished preparing masking and provisioning columnlists
    2022-11-15T04:09:42,359Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Hop generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,359Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - atLeastOneColFound : true
    2022-11-15T04:09:42,359Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Select value step generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,399Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAG_SURNAME_SEQ|
    2022-11-15T04:09:42,406Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |6|
    2022-11-15T04:09:42,409Z [pool-5-thread-6] INFO c.d.d.masking.steps.UpdateImpl - ~~~~~~~~~~~~~~~~~~~~~~ update step :: extension ~~~~~~~~~~~~~~~~
    2022-11-15T04:09:42,409Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## slColList = []
    2022-11-15T04:09:42,409Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## minMaxColList = []
    2022-11-15T04:09:42,414Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Output steps generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,463Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAG_SURNAME_SEQ|
    2022-11-15T04:09:42,467Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |6|
    2022-11-15T04:09:42,470Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAG_SURNAME: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env BOSSPKG, Connector BOSSSNAP_BOSSPKG: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: Lookup and input steps generation finished
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: Get-data-from xml and decrypt steps generation finished
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - XF-generateXML - isInventoryPresent is True.
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Split-field and constant steps generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,471Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Stream-lkup steps generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,515Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAG_SURNAME_SEQ|
    2022-11-15T04:09:42,522Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |6|
    2022-11-15T04:09:42,524Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - select-value and SM table input steps generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,524Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - SM steps generation finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,524Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: User-defined steps generation finished
    2022-11-15T04:09:42,524Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: Dump-distinct and seq-id in-place steps generation finished
    2022-11-15T04:09:42,525Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: MA-algo table input/output steps generation finished
    2022-11-15T04:09:42,525Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAG_SURNAME: table-input/ output steps for MA generation finished
    2022-11-15T04:09:42,527Z [pool-5-thread-6] WARN c.d.d.xmlartist.XmlArtist - Step 'SegColSelect values' is not reachable.
    2022-11-15T04:09:42,528Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - marshalling of transformation object finished for table:MSAG_SURNAME
    2022-11-15T04:09:42,529Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Finished generating transformation steps for table:MSAG_SURNAME
    2022-11-15T04:09:42,529Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST : Started generating transformation steps
    2022-11-15T04:09:42,532Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST : Finished preparing masking and provisioning columnlists
    2022-11-15T04:09:42,553Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Hop generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,553Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - atLeastOneColFound : true
    2022-11-15T04:09:42,553Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Select value step generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,594Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,599Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_DATE_FROM|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_SCHD_CD|
    2022-11-15T04:09:42,600Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:09:42,602Z [pool-5-thread-6] INFO c.d.d.masking.steps.UpdateImpl - ~~~~~~~~~~~~~~~~~~~~~~ update step :: extension ~~~~~~~~~~~~~~~~
    2022-11-15T04:09:42,602Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## slColList = []
    2022-11-15T04:09:42,602Z [pool-5-thread-6] INFO c.d.d.masking.steps.SelectValues - ########## minMaxColList = []
    2022-11-15T04:09:42,606Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Output steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,646Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_DATE_FROM|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_SCHD_CD|
    2022-11-15T04:09:42,651Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAH_PER_COV_HIST: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.masking.steps.TableInputImpl - Env BOSSPKG, Connector BOSSSNAP_BOSSPKG: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: Lookup and input steps generation finished
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: Get-data-from xml and decrypt steps generation finished
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - XF-generateXML - isInventoryPresent is True.
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Split-field and constant steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,655Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Stream-lkup steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,689Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_DATE_FROM|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_SCHD_CD|
    2022-11-15T04:09:42,697Z [pool-5-thread-6] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:09:42,699Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - select-value and SM table input steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,699Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - SM steps generation finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,700Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: User-defined steps generation finished
    2022-11-15T04:09:42,700Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: Dump-distinct and seq-id in-place steps generation finished
    2022-11-15T04:09:42,702Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: MA-algo table input/output steps generation finished
    2022-11-15T04:09:42,702Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Job 8, Table MSAH_PER_COV_HIST: table-input/ output steps for MA generation finished
    2022-11-15T04:09:42,707Z [pool-5-thread-6] WARN c.d.d.xmlartist.XmlArtist - Step 'SegColSelect values' is not reachable.
    2022-11-15T04:09:42,709Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - marshalling of transformation object finished for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,711Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Finished generating transformation steps for table:MSAH_PER_COV_HIST
    2022-11-15T04:09:42,714Z [pool-5-thread-6] INFO c.d.dmsApplicator.ApplicatorUtil - [JOB_ID_8_202] Saved Job details in job history table
    2022-11-15T04:09:42,721Z [pool-5-thread-6] INFO c.d.d.j.t.JobXMLGenerator - isCreateIdentityColumnFlag:: ::false
    2022-11-15T04:09:42,721Z [pool-5-thread-6] INFO c.d.d.j.t.JobXMLGenerator - logFolder /var/delphix/masking/logs/JobLogs
    2022-11-15T04:09:42,721Z [pool-5-thread-6] INFO c.d.d.j.t.JobXMLGenerator - inner job filePath >>>>>>>>>>>>>>>>>>>>>>>>>>> /var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8
    2022-11-15T04:09:42,725Z [pool-5-thread-6] INFO c.d.d.j.t.JobXMLGenerator - Job 8, Env BOSSPKG, Ruleset bosspkg_new: kettle xml path /var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8
    2022-11-15T04:09:42,727Z [pool-5-thread-6] WARN c.d.d.xmlartist.XmlArtist - Step 'ABORT_JOB_FOR_MA' is not reachable.
    2022-11-15T04:09:42,728Z [pool-5-thread-6] INFO c.d.d.m.t.MaskingMarshalling - Transformation XML completed successfully....
    2022-11-15T04:09:42,728Z [pool-5-thread-6] INFO com.dmsuite.manager.JobManager - prescript query to store in transformation generated successfully.
    2022-11-15T04:09:42,734Z [pool-5-thread-6] INFO com.dmsuite.manager.JobManager - Job and collection 8
    2022-11-15T04:09:42,799Z [pool-5-thread-6] INFO com.dmsuite.manager.JobManager - postscript query to store in transformation generated successfully.
    2022-11-15T04:09:42,804Z [pool-5-thread-6] INFO com.dmsuite.manager.JobManager - Job and collection 8
    2022-11-15T04:09:42,861Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - prescript transformation generate successfully
    2022-11-15T04:09:42,861Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - postscript transformation generate successfully
    2022-11-15T04:09:42,861Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - targetConnector.getInstanceNm():::oracle
    2022-11-15T04:09:42,871Z [pool-5-thread-6] INFO c.d.dmsApplicator.ApplicatorUtil - In Run Command line job
    2022-11-15T04:09:42,872Z [pool-5-thread-6] INFO c.d.dmsApplicator.ApplicatorUtil - OSParamenter :l
    2022-11-15T04:09:42,873Z [pool-5-thread-6] INFO c.d.dmsApplicator.ApplicatorUtil - shCommand :/opt/delphix/masking/DMSApplicator/kitchen.sh /file:/var/delphix/masking/output/BOSSPKG/DMSApplicator/bosspkg_new/8/8.xml -level:Basic
    2022-11-15T04:09:42,875Z [pool-5-thread-6] INFO c.d.dmsApplicator.ApplicatorUtil - JAVA Options: -Xms1024m -Xmx1024m -Xss256m -DMASKING_HOME=/opt/delphix/masking -DMASKING_DATA=/var/delphix/masking -Duser.home=/var/delphix/masking/user_home -DPENTAHO_METASTORE_FOLDER=/var/delphix/masking/DMSApplicator -Djavax.net.ssl.trustStore=/var/delphix/server/etc/.truststore -Djavax.net.ssl.keyStore=/var/delphix/server/etc/.keystore -Djavax.xml.parsers.DocumentBuilderFactory=org.apache.xerces.jaxp.DocumentBuilderFactoryImpl
    2022-11-15T04:09:42,884Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 0 detected, some features will be unavailable
    2022-11-15T04:09:42,885Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] Consider installing the package with apt-get or yum.
    2022-11-15T04:09:42,885Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] e.g. 'sudo apt-get install libwebkitgtk-1.0-0'
    2022-11-15T04:09:42,885Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] #######################################################################
    2022-11-15T04:09:46,106Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] Invalid entry, ignoring '/opt/delphix/masking/DMSApplicator/launcher/../../../../../var/delphix/masking/resources/jarfiles/db2jcc_license_cisuz.jar'
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class com.masking.MaskingTwoWayPasswordEncoder registered for plugin type 'TwoWayPasswordEncoder'
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] Loading security manager
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - Kitchen - Logging is at level : Basic
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - Kitchen - Start of run.
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class com.masking.MaskingTwoWayPasswordEncoder registered for plugin type 'TwoWayPasswordEncoder'
    2022-11-15T04:09:46,107Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixFileOutputStepMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixTableInsertStepMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.customFileOutput.plugin.DelphixTableUpdateStepMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.customFileInput.plugin.DelphixFileInputStepMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.customFileInput.plugin.DelphixTableInputStepMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class com.dmsuite.kettle.vsaminput.VSAMInputMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class com.dmsuite.kettle.vsamoutput.VSAMOutputMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.StaxCustomInputStep.CustomXMLInputStreamMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class com.delphix.kettle.algorithmStep.AlgorithmStepMetadata registered for plugin type 'Step'
    2022-11-15T04:09:46,108Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:44 - General - Plugin class dmsuite.charStreaming.plugin.CharStreamingFileInputMeta registered for plugin type 'Step'
    2022-11-15T04:09:46,109Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:45 - 8_202 - Start of job execution
    2022-11-15T04:09:46,109Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:45 - 8_202 - Starting entry [PRESCRIPT TRANSFORMATION]
    2022-11-15T04:09:46,114Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:45 - PRESCRIPT TRANSFORMATION - Loading transformation from XML file [/var/delphix/masking//output/BOSSPKG/DMSApplicator/bosspkg_new/8/KETTLE_PRESCRIPT_TRANSFORMATION_8.xml]
    2022-11-15T04:09:46,114Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:45 - PRESCRIPT TRANSFORMATION - Using legacy execution engine
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:45 - Prescript_Transformation - Dispatching started for transformation [Prescript_Transformation]
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : An error occurred, processing will be stopped:
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 - Couldn't execute SQL: alter table MSAF_PER_COV disable constraint PK_MSAF_PER_COV
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 -
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 - ORA-02297: cannot disable constraint (BOSSPKG.PK_MSAF_PER_COV) - dependencies exist
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Error initializing step [Execute_Prescript]
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Prescript_Transformation - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Step [Execute_Prescript.0] failed to initialize!
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Execute_Prescript.0 - Finished reading query, closing connection.
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Unable to prepare for execution of the transformation
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : org.pentaho.di.core.exception.KettleException:
    2022-11-15T04:09:46,115Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - We failed to initialize at least one step. Execution can not begin!
    2022-11-15T04:09:46,116Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION -
    2022-11-15T04:09:46,116Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION -
    2022-11-15T04:09:46,116Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.prepareExecution(Trans.java:1157)
    2022-11-15T04:09:46,116Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.execute(Trans.java:627)
    2022-11-15T04:09:46,142Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.entries.trans.JobEntryTrans.execute(JobEntryTrans.java:1152)
    2022-11-15T04:09:46,142Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:724)
    2022-11-15T04:09:46,143Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:865)
    2022-11-15T04:09:46,143Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:546)
    2022-11-15T04:09:46,143Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - PRESCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.run(Job.java:436)
    2022-11-15T04:09:46,143Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - 8_202 - Starting entry [ABORT_JOB_FOR_PRESCRIPT]
    2022-11-15T04:09:46,145Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - ABORT_JOB_FOR_PRESCRIPT - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Job failed, because of Pre-Script execution failure.
    2022-11-15T04:09:46,149Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - 8_202 - Finished job entry [ABORT_JOB_FOR_PRESCRIPT] (result=[false])
    2022-11-15T04:09:46,149Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - 8_202 - Finished job entry [PRESCRIPT TRANSFORMATION] (result=[false])
    2022-11-15T04:09:46,149Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - 8_202 - Job execution finished
    2022-11-15T04:09:46,149Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Kitchen - Finished!
    2022-11-15T04:09:46,149Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Kitchen - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Finished with errors
    2022-11-15T04:09:46,150Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Kitchen - Start=2022/11/15 04:09:44.249, Stop=2022/11/15 04:09:46.120
    2022-11-15T04:09:46,150Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] 2022/11/15 04:09:46 - Kitchen - Processing ended after 1 seconds.
    2022-11-15T04:09:46,150Z [pool-5-thread-6] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_202] p.waitFor() is :: 1
    2022-11-15T04:09:46,150Z [pool-5-thread-6] ERROR c.d.d.m.t.RunServiceImpl - Failed to run Kettle without error ::
    com.dmsuite.exception.JobFailedException: Kettle returned a non zero exit value: 1
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1617)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    2022-11-15T04:09:46,155Z [pool-5-thread-6] INFO c.dmsuite.threads.TaskMonitorService - EXECUTIONS mask Task with id 202 deregistered from the monitoring
    2022-11-15T04:09:46,155Z [pool-5-thread-6] INFO c.d.t.ExecutionProgressReporter - Removing execution '202' from being tracked.
    2022-11-15T04:09:46,175Z [pool-5-thread-6] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAF_PER_COV-f00d27ac-b712-31f7-98be-046dd0bae7d4_202'. There was a star log error found for the transformation
    2022-11-15T04:09:46,186Z [pool-5-thread-6] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAG_SURNAME-df65bfe2-07da-35d7-9b35-44bd108c17ce_202'. There was a star log error found for the transformation
    2022-11-15T04:09:46,198Z [pool-5-thread-6] ERROR c.d.d.m.t.RunServiceImpl - Failed to transform 'KETTLE_MASK_XML_8_MSAH_PER_COV_HIST-c4cabc27-69e5-3d0b-b489-4752a4aa1edf_202'. There was a star log error found for the transformation
    2022-11-15T04:09:46,225Z [pool-5-thread-6] ERROR c.dmsuite.threads.JobExecutorService - [JOB_ID_8_202] - Execution 202 for job 8 failed
    com.dmsuite.exception.JobFailedException: Exception executing job 8:
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1170)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    Caused by: com.dmsuite.exception.JobFailedException: Job has failed due to error in running Kettle
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1635)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    ... 8 common frames omitted
    Caused by: com.dmsuite.exception.JobFailedException: Kettle returned a non zero exit value: 1
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1617)
    ... 9 common frames omitted
    2022-11-15T04:09:46,231Z [pool-5-thread-6] INFO c.d.report.core.UserReportGenerator - jobNm BOSSPKG, displayEnvName BOSSPKG : Generating pdf report for masking
    2022-11-15T04:09:46,438Z [pool-5-thread-6] INFO c.d.report.core.UserReportGenerator - Masking report pdf file path: /var/delphix/masking/reports/masking_202_Tue_Nov_15_040946_UTC_2022.pdf
    2022-11-15T04:09:56,634Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.common.utils.FileDownloadUtil - Downloading file /var/delphix/masking/logs/JobLogs/8_202.log
    2022-11-15T04:10:29,317Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 10875393
    2022-11-15T04:10:29,317Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAF_PER_COV with execution 202 is 10875393
    2022-11-15T04:10:29,380Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAG_SURNAME_SEQ|
    2022-11-15T04:10:29,386Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |6|
    2022-11-15T04:10:29,389Z [Thread-94] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAG_SURNAME: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:10:29,389Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - XF-tableInputSQL: SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:10:29,389Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - fetching total rows for table MSAG_SURNAME with execution 202
    2022-11-15T04:10:29,389Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - ####### connection:oracle.jdbc.driver.T4CConnection@4a86a892 sqlQuery:SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAG_SURNAME_SEQ" FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:10:29,389Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - Before calculating count. Query to get count is :: SELECT COUNT(*) FROM "BOSSPKG"."MSAG_SURNAME"
    2022-11-15T04:10:29,886Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 1887425
    2022-11-15T04:10:29,886Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAG_SURNAME with execution 202 is 1887425
    2022-11-15T04:10:29,931Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - ownerName: |BOSSPKG|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAA_CONTRIBNO|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_BIRTH_DATE|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_GIVENAME|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_INITIAL|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAF_RELNSHIP|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_DATE_FROM|
    2022-11-15T04:10:29,935Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumn: |MSAH_SCHD_CD|
    2022-11-15T04:10:29,936Z [Thread-94] INFO c.d.d.masking.steps.StepImpl - XF-getPrimaryColumnNames - pkColumns size: |7|
    2022-11-15T04:10:29,938Z [Thread-94] INFO c.d.d.masking.steps.TableInputImpl - Env 5, Ruleset bosspkg_new, table MSAH_PER_COV_HIST: Query to source DB SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:10:29,938Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - XF-tableInputSQL: SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:10:29,938Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - fetching total rows for table MSAH_PER_COV_HIST with execution 202
    2022-11-15T04:10:29,938Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - ####### connection:oracle.jdbc.driver.T4CConnection@4a86a892 sqlQuery:SELECT ROWID, "MSAF_GIVENAME" , "MSAA_CONTRIBNO" , "MSAF_BIRTH_DATE" , "MSAF_INITIAL" , "MSAF_RELNSHIP" , "MSAH_DATE_FROM" , "MSAH_SCHD_CD" FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:10:29,938Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - Before calculating count. Query to get count is :: SELECT COUNT(*) FROM "BOSSPKG"."MSAH_PER_COV_HIST"
    2022-11-15T04:10:31,724Z [Thread-94] INFO c.d.common.utils.MonitorJobUtil - After calculating count. Total count is :: 6917565
    2022-11-15T04:10:31,724Z [Thread-94] INFO com.dmsuite.manager.MonitorManager - total rows for table MSAH_PER_COV_HIST with execution 202 is 6917565
    2022-11-15T04:10:31,729Z [Thread-94] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAF_PER_COV' in execution '202' with count '10875393'.
    2022-11-15T04:10:31,731Z [Thread-94] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAG_SURNAME' in execution '202' with count '1887425'.
    2022-11-15T04:10:31,733Z [Thread-94] INFO c.d.jobs.monitor.MonitorCountThread - Successfully updated total row count for table 'MSAH_PER_COV_HIST' in execution '202' with count '6917565'.
    2022-11-15T04:10:31,733Z [Thread-94] INFO c.d.jobs.monitor.MonitorCountThread - Execution '202' in environment 'BOSSPKG': Total table count 3
    Total rows in job 19680383
    2022-11-15T04:23:24,104Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.s.ProfilerSettingsController - in ProfilerController
    2022-11-15T04:23:38,122Z [http-nio-127.0.0.1-8284-exec-2] INFO c.d.common.utils.FileDownloadUtil - Downloading file /var/delphix/masking/logs/JobLogs/8_202.log

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 3.  RE: Unable to disable constraints-Oracle

    Posted 11-15-2022 12:31:00 AM
    Hi Everyone, 

    Just to keep you posted, I am able to disable the constraints as pre-sql script but couldn't enable them via post-sql script & getting error:


    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:34 - DelphixTableUpdate.0 - linenr 4000000
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - Table input.0 - linenr 4050000
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - Table input.0 - JobMemoryManager: Pause 3083/3355ms (92%) Heap 3%
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - Select values.0 - linenr 4050000
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - Get All Lookups Values.0 - Linenr 4050000
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - Delphix Algorithm.0 - Rows Read: 4050000 Rows Written: 4044000 Timing (InputWait/Run/OutputWait) 98.8%/1%/0.2%
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:36 - SelectValues_MetaData.0 - linenr 4050000
    2022-11-15T05:39:55,581Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:37 - DelphixTableUpdate.0 - linenr 4050000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:39 - Table input.0 - linenr 4100000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:39 - Table input.0 - JobMemoryManager: Pause 3308/3557ms (93%) Heap 3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:40 - Select values.0 - linenr 4100000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:40 - Get All Lookups Values.0 - Linenr 4100000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:40 - Delphix Algorithm.0 - Rows Read: 4100000 Rows Written: 4096000 Timing (InputWait/Run/OutputWait) 98.6%/1.1%/0.2%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:40 - SelectValues_MetaData.0 - linenr 4100000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:41 - DelphixTableUpdate.0 - linenr 4100000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - Table input.0 - linenr 4150000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - Table input.0 - JobMemoryManager: Pause 3128/3375ms (93%) Heap 3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - Select values.0 - linenr 4150000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - Get All Lookups Values.0 - Linenr 4150000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - Delphix Algorithm.0 - Rows Read: 4150000 Rows Written: 4144000 Timing (InputWait/Run/OutputWait) 98.6%/1.2%/0.2%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:43 - SelectValues_MetaData.0 - linenr 4150000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:44 - DelphixTableUpdate.0 - linenr 4150000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - Table input.0 - linenr 4200000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - Table input.0 - JobMemoryManager: Pause 2848/3082ms (92%) Heap 3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - Select values.0 - linenr 4200000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - Get All Lookups Values.0 - Linenr 4200000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - Delphix Algorithm.0 - Rows Read: 4200000 Rows Written: 4196000 Timing (InputWait/Run/OutputWait) 98.2%/1.4%/0.3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:46 - SelectValues_MetaData.0 - linenr 4200000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:47 - DelphixTableUpdate.0 - linenr 4200000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - Table input.0 - linenr 4250000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - Table input.0 - JobMemoryManager: Pause 2333/2621ms (89%) Heap 3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - Select values.0 - linenr 4250000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - Get All Lookups Values.0 - Linenr 4250000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - Delphix Algorithm.0 - Rows Read: 4250000 Rows Written: 4244000 Timing (InputWait/Run/OutputWait) 98.4%/1.4%/0.2%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:49 - SelectValues_MetaData.0 - linenr 4250000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:50 - DelphixTableUpdate.0 - linenr 4250000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - Table input.0 - linenr 4300000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - Table input.0 - JobMemoryManager: Pause 2779/3057ms (91%) Heap 3%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - Select values.0 - linenr 4300000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - Get All Lookups Values.0 - Linenr 4300000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - Delphix Algorithm.0 - Rows Read: 4300000 Rows Written: 4296000 Timing (InputWait/Run/OutputWait) 98.6%/1.2%/0.2%
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:52 - SelectValues_MetaData.0 - linenr 4300000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:53 - DelphixTableUpdate.0 - linenr 4300000
    2022-11-15T05:39:55,582Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - Table input.0 - linenr 4350000
    2022-11-15T05:39:55,583Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - Table input.0 - JobMemoryManager: Pause 3148/3422ms (92%) Heap 3%
    2022-11-15T05:39:55,583Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - Select values.0 - linenr 4350000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - Get All Lookups Values.0 - Linenr 4350000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - Delphix Algorithm.0 - Rows Read: 4350000 Rows Written: 4344000 Timing (InputWait/Run/OutputWait) 98.9%/1%/0.2%
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:55 - SelectValues_MetaData.0 - linenr 4350000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:57 - DelphixTableUpdate.0 - linenr 4350000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - Table input.0 - linenr 4400000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - Table input.0 - JobMemoryManager: Pause 3309/3538ms (94%) Heap 3%
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - Select values.0 - linenr 4400000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - Get All Lookups Values.0 - Linenr 4400000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - Delphix Algorithm.0 - Rows Read: 4400000 Rows Written: 4396000 Timing (InputWait/Run/OutputWait) 98.7%/1%/0.3%
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:39:59 - SelectValues_MetaData.0 - linenr 4400000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:00 - DelphixTableUpdate.0 - linenr 4400000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Table input.0 - linenr 4450000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Table input.0 - JobMemoryManager: Pause 2849/3133ms (91%) Heap 3%
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Select values.0 - linenr 4450000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Get All Lookups Values.0 - Linenr 4450000
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Delphix Algorithm.0 - Rows Read: 4450000 Rows Written: 4444000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:40:20,061Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - SelectValues_MetaData.0 - linenr 4450000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:02 - Table input.0 - ThroughputLogger:interval 38.584 MB (460000 rows) counted in 30.000 sec; throughput = 1.286 MB/sec
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:03 - DelphixTableUpdate.0 - linenr 4450000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - Table input.0 - linenr 4500000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - Table input.0 - JobMemoryManager: Pause 2716/2969ms (91%) Heap 3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - Select values.0 - linenr 4500000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - Get All Lookups Values.0 - Linenr 4500000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - Delphix Algorithm.0 - Rows Read: 4500000 Rows Written: 4496000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:05 - SelectValues_MetaData.0 - linenr 4500000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:06 - DelphixTableUpdate.0 - linenr 4500000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:07 - Table input.0 - linenr 4550000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:07 - Table input.0 - JobMemoryManager: Pause 2560/2791ms (92%) Heap 3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:08 - Select values.0 - linenr 4550000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:08 - Get All Lookups Values.0 - Linenr 4550000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:08 - Delphix Algorithm.0 - Rows Read: 4550000 Rows Written: 4544000 Timing (InputWait/Run/OutputWait) 98.1%/1.6%/0.3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:08 - SelectValues_MetaData.0 - linenr 4550000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:09 - DelphixTableUpdate.0 - linenr 4550000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - Table input.0 - linenr 4600000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - Table input.0 - JobMemoryManager: Pause 3177/3387ms (94%) Heap 3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - Select values.0 - linenr 4600000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - Get All Lookups Values.0 - Linenr 4600000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - Delphix Algorithm.0 - Rows Read: 4600000 Rows Written: 4596000 Timing (InputWait/Run/OutputWait) 98.8%/1.1%/0.1%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:11 - SelectValues_MetaData.0 - linenr 4600000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:12 - DelphixTableUpdate.0 - linenr 4600000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - Table input.0 - linenr 4650000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - Table input.0 - JobMemoryManager: Pause 2584/2814ms (92%) Heap 3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - Select values.0 - linenr 4650000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - Get All Lookups Values.0 - Linenr 4650000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - Delphix Algorithm.0 - Rows Read: 4650000 Rows Written: 4644000 Timing (InputWait/Run/OutputWait) 98.6%/1.2%/0.3%
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:14 - SelectValues_MetaData.0 - linenr 4650000
    2022-11-15T05:40:20,062Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:15 - DelphixTableUpdate.0 - linenr 4650000
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - Table input.0 - linenr 4700000
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - Table input.0 - JobMemoryManager: Pause 2711/2958ms (92%) Heap 3%
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - Select values.0 - linenr 4700000
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - Get All Lookups Values.0 - Linenr 4700000
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - Delphix Algorithm.0 - Rows Read: 4700000 Rows Written: 4696000 Timing (InputWait/Run/OutputWait) 98.3%/1.3%/0.3%
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:17 - SelectValues_MetaData.0 - linenr 4700000
    2022-11-15T05:40:20,063Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:18 - DelphixTableUpdate.0 - linenr 4700000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - Table input.0 - linenr 4750000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - Table input.0 - JobMemoryManager: Pause 2674/2916ms (92%) Heap 3%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - Select values.0 - linenr 4750000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - Get All Lookups Values.0 - Linenr 4750000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - Delphix Algorithm.0 - Rows Read: 4750000 Rows Written: 4744000 Timing (InputWait/Run/OutputWait) 98.7%/1.1%/0.2%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:20 - SelectValues_MetaData.0 - linenr 4750000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:21 - DelphixTableUpdate.0 - linenr 4750000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - Table input.0 - linenr 4800000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - Table input.0 - JobMemoryManager: Pause 2743/2970ms (92%) Heap 3%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - Select values.0 - linenr 4800000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - Get All Lookups Values.0 - Linenr 4800000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - Delphix Algorithm.0 - Rows Read: 4800000 Rows Written: 4796000 Timing (InputWait/Run/OutputWait) 98.4%/1.4%/0.2%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:23 - SelectValues_MetaData.0 - linenr 4800000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:24 - DelphixTableUpdate.0 - linenr 4800000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - Table input.0 - linenr 4850000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - Table input.0 - JobMemoryManager: Pause 2481/2703ms (92%) Heap 3%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - Select values.0 - linenr 4850000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - Get All Lookups Values.0 - Linenr 4850000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - Delphix Algorithm.0 - Rows Read: 4850000 Rows Written: 4844000 Timing (InputWait/Run/OutputWait) 98.4%/1.3%/0.2%
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:25 - SelectValues_MetaData.0 - linenr 4850000
    2022-11-15T05:40:39,752Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:26 - DelphixTableUpdate.0 - linenr 4850000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - Table input.0 - linenr 4900000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - Table input.0 - JobMemoryManager: Pause 2351/2571ms (91%) Heap 3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - Select values.0 - linenr 4900000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - Get All Lookups Values.0 - Linenr 4900000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - Delphix Algorithm.0 - Rows Read: 4900000 Rows Written: 4896000 Timing (InputWait/Run/OutputWait) 98.4%/1.3%/0.2%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:28 - SelectValues_MetaData.0 - linenr 4900000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:29 - DelphixTableUpdate.0 - linenr 4900000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - Table input.0 - linenr 4950000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - Table input.0 - JobMemoryManager: Pause 2803/3019ms (93%) Heap 3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - Select values.0 - linenr 4950000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - Get All Lookups Values.0 - Linenr 4950000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - Delphix Algorithm.0 - Rows Read: 4950000 Rows Written: 4944000 Timing (InputWait/Run/OutputWait) 98.5%/1.2%/0.3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:31 - SelectValues_MetaData.0 - linenr 4950000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:32 - DelphixTableUpdate.0 - linenr 4950000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:32 - Table input.0 - ThroughputLogger:interval 43.614 MB (520000 rows) counted in 30.000 sec; throughput = 1.454 MB/sec
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - Table input.0 - linenr 5000000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - Table input.0 - JobMemoryManager: Pause 2587/2852ms (91%) Heap 3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - Select values.0 - linenr 5000000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - Get All Lookups Values.0 - Linenr 5000000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - Delphix Algorithm.0 - Rows Read: 5000000 Rows Written: 4996000 Timing (InputWait/Run/OutputWait) 98.5%/1.2%/0.3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:34 - SelectValues_MetaData.0 - linenr 5000000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:35 - DelphixTableUpdate.0 - linenr 5000000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - Table input.0 - linenr 5050000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - Table input.0 - JobMemoryManager: Pause 2468/2753ms (90%) Heap 3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - Select values.0 - linenr 5050000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - Get All Lookups Values.0 - Linenr 5050000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - Delphix Algorithm.0 - Rows Read: 5050000 Rows Written: 5044000 Timing (InputWait/Run/OutputWait) 98.2%/1.6%/0.2%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:36 - SelectValues_MetaData.0 - linenr 5050000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:37 - DelphixTableUpdate.0 - linenr 5050000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - Table input.0 - linenr 5100000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - Table input.0 - JobMemoryManager: Pause 2555/2794ms (91%) Heap 3%
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - Select values.0 - linenr 5100000
    2022-11-15T05:40:39,753Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - Get All Lookups Values.0 - Linenr 5100000
    2022-11-15T05:41:02,356Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - Delphix Algorithm.0 - Rows Read: 5100000 Rows Written: 5096000 Timing (InputWait/Run/OutputWait) 98.4%/1.3%/0.3%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:39 - SelectValues_MetaData.0 - linenr 5100000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:41 - DelphixTableUpdate.0 - linenr 5100000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - Table input.0 - linenr 5150000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - Table input.0 - JobMemoryManager: Pause 2837/3113ms (91%) Heap 3%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - Select values.0 - linenr 5150000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - Get All Lookups Values.0 - Linenr 5150000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - Delphix Algorithm.0 - Rows Read: 5150000 Rows Written: 5144000 Timing (InputWait/Run/OutputWait) 98.8%/1.1%/0.2%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:42 - SelectValues_MetaData.0 - linenr 5150000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:44 - DelphixTableUpdate.0 - linenr 5150000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - Table input.0 - linenr 5200000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - Table input.0 - JobMemoryManager: Pause 2671/2923ms (91%) Heap 3%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - Select values.0 - linenr 5200000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - Get All Lookups Values.0 - Linenr 5200000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - Delphix Algorithm.0 - Rows Read: 5200000 Rows Written: 5196000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:45 - SelectValues_MetaData.0 - linenr 5200000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:46 - DelphixTableUpdate.0 - linenr 5200000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - Table input.0 - linenr 5250000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - Table input.0 - JobMemoryManager: Pause 2372/2623ms (90%) Heap 3%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - Select values.0 - linenr 5250000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - Get All Lookups Values.0 - Linenr 5250000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - Delphix Algorithm.0 - Rows Read: 5250000 Rows Written: 5244000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:48 - SelectValues_MetaData.0 - linenr 5250000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:49 - DelphixTableUpdate.0 - linenr 5250000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - Table input.0 - linenr 5300000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - Table input.0 - JobMemoryManager: Pause 2772/3035ms (91%) Heap 3%
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - Select values.0 - linenr 5300000
    2022-11-15T05:41:02,357Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - Get All Lookups Values.0 - Linenr 5300000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - Delphix Algorithm.0 - Rows Read: 5300000 Rows Written: 5296000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:51 - SelectValues_MetaData.0 - linenr 5300000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:52 - DelphixTableUpdate.0 - linenr 5300000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - Table input.0 - linenr 5350000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - Table input.0 - JobMemoryManager: Pause 2871/3241ms (89%) Heap 3%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - Select values.0 - linenr 5350000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - Get All Lookups Values.0 - Linenr 5350000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - Delphix Algorithm.0 - Rows Read: 5350000 Rows Written: 5344000 Timing (InputWait/Run/OutputWait) 98.8%/1%/0.2%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:54 - SelectValues_MetaData.0 - linenr 5350000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:55 - DelphixTableUpdate.0 - linenr 5350000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - Table input.0 - linenr 5400000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - Table input.0 - JobMemoryManager: Pause 2264/2483ms (91%) Heap 3%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - Select values.0 - linenr 5400000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - Get All Lookups Values.0 - Linenr 5400000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - Delphix Algorithm.0 - Rows Read: 5400000 Rows Written: 5396000 Timing (InputWait/Run/OutputWait) 98%/1.7%/0.3%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - SelectValues_MetaData.0 - linenr 5400000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:57 - DelphixTableUpdate.0 - linenr 5400000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - Table input.0 - linenr 5450000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - Table input.0 - JobMemoryManager: Pause 2309/2550ms (91%) Heap 3%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - Select values.0 - linenr 5450000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - Get All Lookups Values.0 - Linenr 5450000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - Delphix Algorithm.0 - Rows Read: 5450000 Rows Written: 5444000 Timing (InputWait/Run/OutputWait) 98.2%/1.5%/0.2%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:40:59 - SelectValues_MetaData.0 - linenr 5450000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:00 - DelphixTableUpdate.0 - linenr 5450000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Table input.0 - linenr 5500000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Table input.0 - JobMemoryManager: Pause 2352/2613ms (90%) Heap 3%
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Select values.0 - linenr 5500000
    2022-11-15T05:41:02,358Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Get All Lookups Values.0 - Linenr 5500000
    2022-11-15T05:41:25,843Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Delphix Algorithm.0 - Rows Read: 5500000 Rows Written: 5496000 Timing (InputWait/Run/OutputWait) 98.2%/1.5%/0.3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - SelectValues_MetaData.0 - linenr 5500000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:02 - Table input.0 - ThroughputLogger:interval 44.455 MB (530000 rows) counted in 30.000 sec; throughput = 1.482 MB/sec
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:03 - DelphixTableUpdate.0 - linenr 5500000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - Table input.0 - linenr 5550000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - Table input.0 - JobMemoryManager: Pause 2847/3113ms (91%) Heap 3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - Select values.0 - linenr 5550000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - Get All Lookups Values.0 - Linenr 5550000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - Delphix Algorithm.0 - Rows Read: 5550000 Rows Written: 5544000 Timing (InputWait/Run/OutputWait) 98.7%/1.1%/0.2%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:05 - SelectValues_MetaData.0 - linenr 5550000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:06 - DelphixTableUpdate.0 - linenr 5550000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - Table input.0 - linenr 5600000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - Table input.0 - JobMemoryManager: Pause 2513/2785ms (90%) Heap 3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - Select values.0 - linenr 5600000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - Get All Lookups Values.0 - Linenr 5600000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - Delphix Algorithm.0 - Rows Read: 5600000 Rows Written: 5596000 Timing (InputWait/Run/OutputWait) 98.3%/1.5%/0.2%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:08 - SelectValues_MetaData.0 - linenr 5600000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:09 - DelphixTableUpdate.0 - linenr 5600000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - Table input.0 - linenr 5650000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - Table input.0 - JobMemoryManager: Pause 3248/3509ms (93%) Heap 3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - Select values.0 - linenr 5650000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - Get All Lookups Values.0 - Linenr 5650000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - Delphix Algorithm.0 - Rows Read: 5650000 Rows Written: 5644000 Timing (InputWait/Run/OutputWait) 98.7%/1.2%/0.2%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:11 - SelectValues_MetaData.0 - linenr 5650000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:13 - DelphixTableUpdate.0 - linenr 5650000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - Table input.0 - linenr 5700000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - Table input.0 - JobMemoryManager: Pause 2904/3132ms (93%) Heap 3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - Select values.0 - linenr 5700000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - Get All Lookups Values.0 - Linenr 5700000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - Delphix Algorithm.0 - Rows Read: 5700000 Rows Written: 5696000 Timing (InputWait/Run/OutputWait) 98.4%/1.3%/0.3%
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:14 - SelectValues_MetaData.0 - linenr 5700000
    2022-11-15T05:41:25,844Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:15 - DelphixTableUpdate.0 - linenr 5700000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - Table input.0 - linenr 5750000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - Table input.0 - JobMemoryManager: Pause 2677/2907ms (92%) Heap 3%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - Select values.0 - linenr 5750000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - Get All Lookups Values.0 - Linenr 5750000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - Delphix Algorithm.0 - Rows Read: 5750000 Rows Written: 5744000 Timing (InputWait/Run/OutputWait) 98.7%/1.2%/0.2%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:17 - SelectValues_MetaData.0 - linenr 5750000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:18 - DelphixTableUpdate.0 - linenr 5750000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - Table input.0 - linenr 5800000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - Table input.0 - JobMemoryManager: Pause 2487/2796ms (89%) Heap 3%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - Select values.0 - linenr 5800000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - Get All Lookups Values.0 - Linenr 5800000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - Delphix Algorithm.0 - Rows Read: 5800000 Rows Written: 5796000 Timing (InputWait/Run/OutputWait) 98%/1.7%/0.3%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:20 - SelectValues_MetaData.0 - linenr 5800000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:21 - DelphixTableUpdate.0 - linenr 5800000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - Table input.0 - linenr 5850000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - Table input.0 - JobMemoryManager: Pause 2437/2664ms (91%) Heap 3%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - Select values.0 - linenr 5850000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - Get All Lookups Values.0 - Linenr 5850000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - Delphix Algorithm.0 - Rows Read: 5850000 Rows Written: 5844000 Timing (InputWait/Run/OutputWait) 98.3%/1.6%/0.2%
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:23 - SelectValues_MetaData.0 - linenr 5850000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:24 - DelphixTableUpdate.0 - linenr 5850000
    2022-11-15T05:41:25,845Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - Table input.0 - linenr 5900000
    2022-11-15T05:41:49,204Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - Table input.0 - JobMemoryManager: Pause 2407/2634ms (91%) Heap 3%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - Select values.0 - linenr 5900000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - Get All Lookups Values.0 - Linenr 5900000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - Delphix Algorithm.0 - Rows Read: 5900000 Rows Written: 5896000 Timing (InputWait/Run/OutputWait) 98.2%/1.4%/0.4%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:25 - SelectValues_MetaData.0 - linenr 5900000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:27 - DelphixTableUpdate.0 - linenr 5900000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - Table input.0 - linenr 5950000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - Table input.0 - JobMemoryManager: Pause 3122/3356ms (93%) Heap 3%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - Select values.0 - linenr 5950000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - Get All Lookups Values.0 - Linenr 5950000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - Delphix Algorithm.0 - Rows Read: 5950000 Rows Written: 5944000 Timing (InputWait/Run/OutputWait) 98.9%/0.9%/0.2%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:29 - SelectValues_MetaData.0 - linenr 5950000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:30 - DelphixTableUpdate.0 - linenr 5950000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Table input.0 - linenr 6000000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Table input.0 - JobMemoryManager: Pause 3007/3237ms (93%) Heap 3%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Select values.0 - linenr 6000000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Get All Lookups Values.0 - Linenr 6000000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Delphix Algorithm.0 - Rows Read: 6000000 Rows Written: 5996000 Timing (InputWait/Run/OutputWait) 98.5%/1.2%/0.3%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - SelectValues_MetaData.0 - linenr 6000000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:32 - Table input.0 - ThroughputLogger:interval 41.935 MB (500000 rows) counted in 30.000 sec; throughput = 1.398 MB/sec
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:33 - DelphixTableUpdate.0 - linenr 6000000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - Table input.0 - linenr 6050000
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - Table input.0 - JobMemoryManager: Pause 2959/3256ms (91%) Heap 3%
    2022-11-15T05:41:49,205Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - Select values.0 - linenr 6050000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - Get All Lookups Values.0 - Linenr 6050000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - Delphix Algorithm.0 - Rows Read: 6050000 Rows Written: 6044000 Timing (InputWait/Run/OutputWait) 98.7%/1.1%/0.2%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:35 - SelectValues_MetaData.0 - linenr 6050000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:37 - DelphixTableUpdate.0 - linenr 6050000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - Table input.0 - linenr 6100000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - Table input.0 - JobMemoryManager: Pause 3056/3321ms (92%) Heap 3%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - Select values.0 - linenr 6100000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - Get All Lookups Values.0 - Linenr 6100000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - Delphix Algorithm.0 - Rows Read: 6100000 Rows Written: 6096000 Timing (InputWait/Run/OutputWait) 98.3%/1.4%/0.3%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:39 - SelectValues_MetaData.0 - linenr 6100000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:40 - DelphixTableUpdate.0 - linenr 6100000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - Table input.0 - linenr 6150000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - Table input.0 - JobMemoryManager: Pause 2819/3064ms (92%) Heap 3%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - Select values.0 - linenr 6150000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - Get All Lookups Values.0 - Linenr 6150000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - Delphix Algorithm.0 - Rows Read: 6150000 Rows Written: 6144000 Timing (InputWait/Run/OutputWait) 98.4%/1.4%/0.2%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:42 - SelectValues_MetaData.0 - linenr 6150000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:43 - DelphixTableUpdate.0 - linenr 6150000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - Table input.0 - linenr 6200000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - Table input.0 - JobMemoryManager: Pause 3314/3556ms (93%) Heap 3%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - Select values.0 - linenr 6200000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - Get All Lookups Values.0 - Linenr 6200000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - Delphix Algorithm.0 - Rows Read: 6200000 Rows Written: 6196000 Timing (InputWait/Run/OutputWait) 98.8%/1%/0.2%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:45 - SelectValues_MetaData.0 - linenr 6200000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:46 - DelphixTableUpdate.0 - linenr 6200000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - Table input.0 - linenr 6250000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - Table input.0 - JobMemoryManager: Pause 3289/3530ms (93%) Heap 3%
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - Select values.0 - linenr 6250000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - Get All Lookups Values.0 - Linenr 6250000
    2022-11-15T05:41:49,206Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - Delphix Algorithm.0 - Rows Read: 6250000 Rows Written: 6244000 Timing (InputWait/Run/OutputWait) 98.8%/1.1%/0.1%
    2022-11-15T05:42:15,370Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:49 - SelectValues_MetaData.0 - linenr 6250000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:50 - DelphixTableUpdate.0 - linenr 6250000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - Table input.0 - linenr 6300000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - Table input.0 - JobMemoryManager: Pause 2702/2925ms (92%) Heap 3%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - Select values.0 - linenr 6300000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - Get All Lookups Values.0 - Linenr 6300000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - Delphix Algorithm.0 - Rows Read: 6300000 Rows Written: 6296000 Timing (InputWait/Run/OutputWait) 98.5%/1.4%/0.2%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:52 - SelectValues_MetaData.0 - linenr 6300000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:53 - DelphixTableUpdate.0 - linenr 6300000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - Table input.0 - linenr 6350000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - Table input.0 - JobMemoryManager: Pause 2911/3171ms (92%) Heap 3%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - Select values.0 - linenr 6350000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - Get All Lookups Values.0 - Linenr 6350000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - Delphix Algorithm.0 - Rows Read: 6350000 Rows Written: 6344000 Timing (InputWait/Run/OutputWait) 98.7%/1.1%/0.1%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:55 - SelectValues_MetaData.0 - linenr 6350000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:56 - DelphixTableUpdate.0 - linenr 6350000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - Table input.0 - linenr 6400000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - Table input.0 - JobMemoryManager: Pause 3310/3536ms (94%) Heap 3%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - Select values.0 - linenr 6400000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - Get All Lookups Values.0 - Linenr 6400000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - Delphix Algorithm.0 - Rows Read: 6400000 Rows Written: 6396000 Timing (InputWait/Run/OutputWait) 98.5%/1.3%/0.2%
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:41:58 - SelectValues_MetaData.0 - linenr 6400000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:00 - DelphixTableUpdate.0 - linenr 6400000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Table input.0 - linenr 6450000
    2022-11-15T05:42:15,371Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Table input.0 - JobMemoryManager: Pause 3200/3451ms (93%) Heap 3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Select values.0 - linenr 6450000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Get All Lookups Values.0 - Linenr 6450000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Delphix Algorithm.0 - Rows Read: 6450000 Rows Written: 6444000 Timing (InputWait/Run/OutputWait) 98.8%/1.1%/0.2%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - SelectValues_MetaData.0 - linenr 6450000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:02 - Table input.0 - ThroughputLogger:interval 37.748 MB (450000 rows) counted in 29.999 sec; throughput = 1.258 MB/sec
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:03 - DelphixTableUpdate.0 - linenr 6450000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - Table input.0 - linenr 6500000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - Table input.0 - JobMemoryManager: Pause 2959/3211ms (92%) Heap 3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - Select values.0 - linenr 6500000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - Get All Lookups Values.0 - Linenr 6500000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - Delphix Algorithm.0 - Rows Read: 6500000 Rows Written: 6496000 Timing (InputWait/Run/OutputWait) 98.3%/1.4%/0.3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:05 - SelectValues_MetaData.0 - linenr 6500000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:07 - DelphixTableUpdate.0 - linenr 6500000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - Table input.0 - linenr 6550000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - Table input.0 - JobMemoryManager: Pause 3641/3852ms (95%) Heap 3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - Select values.0 - linenr 6550000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - Get All Lookups Values.0 - Linenr 6550000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - Delphix Algorithm.0 - Rows Read: 6550000 Rows Written: 6544000 Timing (InputWait/Run/OutputWait) 99%/0.9%/0.1%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:09 - SelectValues_MetaData.0 - linenr 6550000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:10 - DelphixTableUpdate.0 - linenr 6550000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - Table input.0 - linenr 6600000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - Table input.0 - JobMemoryManager: Pause 2860/3104ms (92%) Heap 3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - Select values.0 - linenr 6600000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - Get All Lookups Values.0 - Linenr 6600000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - Delphix Algorithm.0 - Rows Read: 6600000 Rows Written: 6596000 Timing (InputWait/Run/OutputWait) 98.2%/1.5%/0.3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:12 - SelectValues_MetaData.0 - linenr 6600000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:13 - DelphixTableUpdate.0 - linenr 6600000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - Table input.0 - linenr 6650000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - Table input.0 - JobMemoryManager: Pause 2656/2917ms (91%) Heap 3%
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - Select values.0 - linenr 6650000
    2022-11-15T05:42:15,372Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - Get All Lookups Values.0 - Linenr 6650000
    2022-11-15T05:42:30,484Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - Delphix Algorithm.0 - Rows Read: 6650000 Rows Written: 6644000 Timing (InputWait/Run/OutputWait) 98.5%/1.2%/0.3%
    2022-11-15T05:42:30,484Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:15 - SelectValues_MetaData.0 - linenr 6650000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:16 - DelphixTableUpdate.0 - linenr 6650000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - Table input.0 - linenr 6700000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - Table input.0 - JobMemoryManager: Pause 1798/2021ms (89%) Heap 3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - Select values.0 - linenr 6700000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - Get All Lookups Values.0 - Linenr 6700000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - Delphix Algorithm.0 - Rows Read: 6700000 Rows Written: 6696000 Timing (InputWait/Run/OutputWait) 97.8%/1.9%/0.3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:17 - SelectValues_MetaData.0 - linenr 6700000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:18 - DelphixTableUpdate.0 - linenr 6700000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - Table input.0 - linenr 6750000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - Table input.0 - JobMemoryManager: Pause 2036/2287ms (89%) Heap 3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - Select values.0 - linenr 6750000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - Get All Lookups Values.0 - Linenr 6750000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - Delphix Algorithm.0 - Rows Read: 6750000 Rows Written: 6744000 Timing (InputWait/Run/OutputWait) 98%/1.7%/0.4%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:19 - SelectValues_MetaData.0 - linenr 6750000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:20 - DelphixTableUpdate.0 - linenr 6750000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - Table input.0 - linenr 6800000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - Table input.0 - JobMemoryManager: Pause 2470/2727ms (91%) Heap 3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - Select values.0 - linenr 6800000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - Get All Lookups Values.0 - Linenr 6800000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - Delphix Algorithm.0 - Rows Read: 6800000 Rows Written: 6796000 Timing (InputWait/Run/OutputWait) 98.2%/1.5%/0.3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:22 - SelectValues_MetaData.0 - linenr 6800000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:23 - DelphixTableUpdate.0 - linenr 6800000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - Table input.0 - linenr 6850000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - Table input.0 - JobMemoryManager: Pause 2650/2902ms (91%) Heap 3%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - Select values.0 - linenr 6850000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - Get All Lookups Values.0 - Linenr 6850000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - Delphix Algorithm.0 - Rows Read: 6850000 Rows Written: 6844000 Timing (InputWait/Run/OutputWait) 98.6%/1.2%/0.2%
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:25 - SelectValues_MetaData.0 - linenr 6850000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:26 - DelphixTableUpdate.0 - linenr 6850000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - linenr 6900000
    2022-11-15T05:42:30,485Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - JobMemoryManager: Pause 2681/2885ms (93%) Heap 3%
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Select values.0 - linenr 6900000
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Get All Lookups Values.0 - Linenr 6900000
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Delphix Algorithm.0 - Rows Read: 6900000 Rows Written: 6896000 Timing (InputWait/Run/OutputWait) 98.4%/1.4%/0.2%
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - SelectValues_MetaData.0 - linenr 6900000
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - JobMemoryManager: Total Pause 380815/416418ms (91%) Heap 34086608b of 1064304640b (3%) GC Count 0
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - ThroughputLogger:interval 38.479 MB (458565 rows) counted in 26.416 sec; throughput = 1.457 MB/sec
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - ThroughputLogger:total 580.213 MB (6917565 rows) counted in 416.418 sec; throughput = 1.393 MB/sec
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - Finished reading query, closing connection.
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Select values.0 - Finished processing (I=0, O=0, R=6917565, W=6917565, U=0, E=0)
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Table input.0 - Finished processing (I=6917565, O=0, R=0, W=6917565, U=0, E=0)
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Get All Lookups Values.0 - Finished processing (I=0, O=0, R=6917565, W=6917565, U=0, E=0)
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Delphix Algorithm.0 - Algorithm step ended 0 worker threads
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:28 - Delphix Algorithm.0 - Finished processing (I=0, O=0, R=6917565, W=6917565, U=0, E=0)
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:29 - SelectValues_MetaData.0 - Finished processing (I=0, O=0, R=6917565, W=6917565, U=0, E=0)
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:29 - DelphixTableUpdate.0 - linenr 6900000
    2022-11-15T05:42:30,486Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:29 - String Cut.0 - Finished processing (I=0, O=0, R=6917565, W=6917565, U=0, E=0)
    2022-11-15T05:43:06,262Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - DelphixTableUpdate.0 - Finished processing (I=6917565, O=0, R=6917565, W=6917565, U=6917565, E=0)
    2022-11-15T05:43:06,262Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - INNER_JOB_8 - Finished job entry [MSAH_PER_COV_HIST-c4cabc27-69e5-3d0b-b489-4752a4aa1edf] (result=[true])
    2022-11-15T05:43:06,262Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - INNER_JOB_8 - Finished job entry [MSAG_SURNAME-df65bfe2-07da-35d7-9b35-44bd108c17ce] (result=[true])
    2022-11-15T05:43:06,262Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - 8_208 - Starting entry [POSTSCRIPT TRANSFORMATION]
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - POSTSCRIPT TRANSFORMATION - Loading transformation from XML file [/var/delphix/masking//output/BOSSPKG/DMSApplicator/bosspkg_new/8/KETTLE_POSTSCRIPT_TRANSFORMATION_8.xml]
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - POSTSCRIPT TRANSFORMATION - Using legacy execution engine
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:42:30 - Postscipt_Transformation - Dispatching started for transformation [Postscipt_Transformation]
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : An error occurred, processing will be stopped:
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 - Couldn't execute SQL: alter table MSAF_PER_COV enable constraint PK_MSAF_PER_COV
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 -
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 - ORA-02437: cannot validate (BOSSPKG.PK_MSAF_PER_COV) - primary key violated
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Error initializing step [Execute_Postscript]
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Postscipt_Transformation - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Step [Execute_Postscript.0] failed to initialize!
    2022-11-15T05:43:06,267Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - Execute_Postscript.0 - Finished reading query, closing connection.
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Unable to prepare for execution of the transformation
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : org.pentaho.di.core.exception.KettleException:
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - We failed to initialize at least one step. Execution can not begin!
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION -
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION -
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.prepareExecution(Trans.java:1157)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.trans.Trans.execute(Trans.java:627)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.entries.trans.JobEntryTrans.execute(JobEntryTrans.java:1152)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:724)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:865)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:865)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:865)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.execute(Job.java:546)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - POSTSCRIPT TRANSFORMATION - at org.pentaho.di.job.Job.run(Job.java:436)
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - 8_208 - Starting entry [ABORT_JOB_FOR_POSTSCRIPT]
    2022-11-15T05:43:06,268Z [pool-5-thread-2] INFO c.d.d.m.t.RunServiceImpl - [JOB_ID_8_208] 2022/11/15 05:43:06 - ABORT_JOB_FOR_POSTSCRIPT - ERROR (version 7.1.0.0-12, build 1 from 2017-05-16 17.18.02 by buildguy) : Job failed, because of Post-Script execution failure.
    2022-11-15T05:43:06,271Z [pool-5-thread-2] ERROR c.d.d.m.t.RunServiceImpl - Failed to run Kettle without error ::
    com.dmsuite.exception.JobFailedException: ---------- Error occurs while, Post-Script ( Post-Script / Enable Constraint / Enable Trigger) execution.
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1546)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    2022-11-15T05:43:06,276Z [pool-5-thread-2] INFO c.dmsuite.threads.TaskMonitorService - EXECUTIONS mask Task with id 208 deregistered from the monitoring
    2022-11-15T05:43:06,276Z [pool-5-thread-2] INFO c.d.t.ExecutionProgressReporter - Removing execution '208' from being tracked.
    2022-11-15T05:43:06,302Z [pool-5-thread-2] ERROR c.dmsuite.threads.JobExecutorService - [JOB_ID_8_208] - Execution 208 for job 8 failed
    com.dmsuite.exception.JobFailedException: Exception executing job 8:
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1170)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:300)
    at com.dmsuite.threads.JobExecutorService$JobCallable.call(JobExecutorService.java:276)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:750)
    Caused by: com.dmsuite.exception.JobFailedException: Job has failed due to error in running Kettle
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1635)
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.run(RunServiceImpl.java:1018)
    ... 8 common frames omitted
    Caused by: com.dmsuite.exception.JobFailedException: ---------- Error occurs while, Post-Script ( Post-Script / Enable Constraint / Enable Trigger) execution.
    at com.dmsuite.dmsApplicator.masking.transformation.RunServiceImpl.runKettleJob(RunServiceImpl.java:1546)
    ... 9 common frames omitted
    2022-11-15T05:43:06,316Z [pool-5-thread-2] INFO c.d.report.core.UserReportGenerator - jobNm BOSSPKG, displayEnvName BOSSPKG : Generating pdf report for masking
    2022-11-15T05:43:06,513Z [pool-5-thread-2] INFO c.d.report.core.UserReportGenerator - Masking report pdf file path: /var/delphix/masking/reports/masking_208_Tue_Nov_15_054306_UTC_2022.pdf
    2022-11-15T05:43:26,979Z [http-nio-127.0.0.1-8284-exec-4] INFO c.d.common.utils.FileDownloadUtil - Downloading file /var/delphix/masking/logs/JobLogs/8_208.log
    2022-11-15T06:00:13,491Z [pool-1-thread-7] INFO c.d.threads.scheduled.PurgeStarTable - Starting the scheduled cleanup of the star table.
    2022-11-15T06:00:13,491Z [pool-1-thread-7] INFO c.d.threads.scheduled.PurgeStarTable - Cleaning entries older than 60 DAYS.
    2022-11-15T06:00:13,495Z [pool-1-thread-1] INFO c.d.t.s.PurgeTransLevelInfoTable - Starting the scheduled cleanup of the trans_level_info table.
    2022-11-15T06:00:13,496Z [pool-1-thread-1] INFO c.d.t.s.PurgeTransLevelInfoTable - Cleaning entries older than 60 DAYS.
    2022-11-15T06:00:13,500Z [pool-1-thread-1] INFO c.d.t.s.PurgeTransLevelInfoTable - Cleaned 0 total entries during this cleanup session.
    2022-11-15T06:00:13,546Z [pool-1-thread-7] INFO c.d.threads.scheduled.PurgeStarTable - Cleaned 0 total entries during this cleanup session.
    2022-11-15T06:16:55,340Z [http-nio-127.0.0.1-8284-exec-5] INFO c.d.common.utils.FileDownloadUtil - Downloading file /var/delphix/masking/logs/JobLogs/8_208.log
    2022-11-15T06:17:05,751Z [http-nio-127.0.0.1-8284-exec-6] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T06:17:05,836Z [http-nio-127.0.0.1-8284-exec-6] INFO c.dmsuite.manager.EnvironmentManager - User is admin: true
    2022-11-15T06:17:09,432Z [http-nio-127.0.0.1-8284-exec-4] INFO c.d.m.a.p.utils.DriverSupportUtil - Successfully loaded driver support class 'class masking.driverSupport.OracleDriverSupport'
    2022-11-15T06:17:09,461Z [http-nio-127.0.0.1-8284-exec-7] INFO c.d.m.a.p.utils.DriverSupportUtil - Successfully loaded driver support class 'class masking.driverSupport.OracleDriverSupport'
    2022-11-15T06:17:38,029Z [http-nio-127.0.0.1-8284-exec-8] INFO c.d.w.s.ProfilerSettingsController - in ProfilerController

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 4.  RE: Unable to disable constraints-Oracle

    Posted 11-21-2022 02:35:00 AM
    Hello Raman,

    From the error logs i could see that there are some duplicates records in that table.
    Please remove the duplicate records and execute the same postscript it should work.

    Cause

    You tried to enable a primary key constraint, but the columns in the primary key either contained NULL values or duplicates.

    Resolution

    This error occurs when you try to enable a primary key when there is data in the table, and the columns that make up the primary key contain either NULL values.

    To find duplicate records:

    select count(1),< COLUMNS> from TABLE_NAME group by <COLUMNS > having count(1)>1;

    To update Duplicate with random + email value

    UPDATE TABLE_NAME SET COLUMN_NAME= (round(DBMS_RANDOM.value(1,1000)))|| TABLE_NAME

    where COLUMN in (select COLUMN from TABLE_NAME group by <COLUMNS > having count(1)>1;)



    ------------------------------
    Pankaj Asegaonkar
    Delphix
    Infosys
    ------------------------------



  • 5.  RE: Unable to disable constraints-Oracle

    Posted 11-21-2022 06:09:00 AM
    Thanks Pankaj!

    However, based on Tino's comments I've tried disabling/enabling the constraint and its not working, atm working with Delphix support to get the issue resolved.

    Will keep you guys posted once I've some way forward!


    Regards,
    Raman

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 6.  RE: Unable to disable constraints-Oracle
    Best Answer

    Posted 11-16-2022 02:13:00 AM
    You need to verify your postscript statement ... and suggest to verify both pre- and postscript, you can execute both in sequence
    outside of the masking engine to verify they are correct. When saving a pre/post script there is no validation of the SQL statement.
    I assume you know that the pre/postscript supports only plain ANSI SQL statements (no variables,no transactions,..).
    Each statement must be one single line and ending with semicolon.
    You may check the system log if there is anything useful for the given time.

    ------------------------------
    Tino Pironti
    Masking SME
    Technical Manager
    Delphix
    ------------------------------



  • 7.  RE: Unable to disable constraints-Oracle

    Posted 11-21-2022 06:11:00 AM
    Thanks Tino! 

    Currently working with Aaron and our internal team to find an alternate/resolution for this, might come back here if there is no suitable choice per our scenario.

    Regards,
    Raman

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 8.  RE: Unable to disable constraints-Oracle

    Posted 11-28-2022 11:39:00 PM
    Edited by Raman Gulati 11-28-2022 11:40:29 PM
    Hi Tino/Experts,

    Just to let you know that PK & FK column masking is achievable in the scenario I've currently with one little PL/SQL code or procedure & requires to be executed as post script, after disabling the constraints via pre-sql script we need to run the PL/sql code to do rest of the job along with enabling constraints (should work as they're simple ANSI SQL statements) but how to run the code via post-sql script is the hiccup.

    Could any one here please advise if we can run the PL/SQL code as part & parcel of masking job or is there a way we can call a script to achieve the desired resolution.


    Regards,
    Raman

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 9.  RE: Unable to disable constraints-Oracle

    Posted 11-29-2022 01:40:00 AM
    Put your PL/SQL code into a procedure or function (without arguments) and simply call procedure/function from the post-script.
    As far as I remember arguments are not possible ... several customers use this approach to run pl/sql.
    Another option is to use virtualization hooks if you use VDBs, on such hook scripts you can run complex PL/SQL.

    ------------------------------
    Tino Pironti
    Masking SME
    Technical Manager
    Delphix
    ------------------------------



  • 10.  RE: Unable to disable constraints-Oracle

    Posted 11-29-2022 11:47:00 PM
    Hi Tino/Team,

    Thanks for quick revert!

    Wanted to keep you posted that upon running the PL/SQL procedure via Post-sql script I am getting below error and its not allowing to run the procedure.


    Is there something missed or driver issue as I've tried various statements in Post-sql script like--

    Execute procedure;
    Procedure only;
    Begin
    Execute procedure;
    end;
    Could you please advise the correct way of calling the PL/sql procedure as didn't find the same in Delphix documentation.

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 11.  RE: Unable to disable constraints-Oracle

    Posted 11-30-2022 01:21:00 AM
    You can use only plain ANSI SQL statements. This means procedural statements are not possible.
    One SQL statement is ONE horizontal line ending with ;
    No variables, no declarations, just call the procedure or statement like :

    alter table X bla bla;
    drop index Y;
    execute procedure_name;

    ------------------------------
    Tino Pironti
    Masking SME
    Technical Manager
    Delphix
    ------------------------------



  • 12.  RE: Unable to disable constraints-Oracle

    Posted 12-05-2022 12:30:00 AM
    Hi Tino/Team,

    Thanks for all your help!

    Just to keep everyone posted here that masking PK/FK columns is bit tedious job & not straight forward as per Delphix documentation.

    However, in the scenario at hand we need to mask names across all 3 tables (Parent & Child) & it should be unique to satisfy the PK/FK constraint along with other columns (part of those constraints). As per Delphix the realistic solution is to use Mapping Algorithm where 1-1 mapping is feasible & that too with external Postgre SQL database to get the efficient performance. In Mapping algorithm, Delphix will always mask XXX to YYY as per the list of values we'll feed & list of values should be equal or greater than input values to be masked to avoid duplicates. 

    In our case we found a work-around where we disabled the constraints with Pre-SQL script, with simple SQL statements ending with semicolon. Post disabling the constraints Delphix masked the names with Secure lookup Algorithm, which caused the issue for PK/FK as it produces duplicates, for e.g., SL algorithm can mask Peter to Ajay and it can also mask Ginny to Ajay, in that case we'll have lot of duplicates as Ajay. To work-around this issue we got very small PL/SQL procedure/script created to remove duplicate names, which does the job for us as it leaves the first occurrence of Ajay & adding 1,2,3,4 & so on as a suffix for remaining Ajay, where-ever it finds it in that column. This way we've no duplicates left anymore and Delphix could be able to enable the constraints back as post-sql script.

    This little PL/SQL procedure saved us from lot of efforts to rope in external database of Postgre SQL and help resolving the enabling PK/FK constraint back after masking all 3 tables together (parent & child) to maintain the referential integrity. Hope this helps for cases where one is looking to mask column containing names & having PK/FK constraint enabled for that column, happy to share more details & help anyone here, if required.

    Also feedback/queries are welcome on this scenario as it might look awkward, but this worked for us.

    Regards,
    Raman  














    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 13.  RE: Unable to disable constraints-Oracle

    Posted 12-05-2022 09:03:00 AM

    Hi Raman,

    You didn't mention the Masking version that you are using but, if you don't mind that the names will be scrambled, you could consider using our CM Alpha numeric algorithm (Character Mapping), which does guarantee uniqueness without the need of an additional procedure.

    We also provide guidance on how to mask Primary keys and Foreign keys in our KBA.

    Regards
    Sandro



    ------------------------------
    Sandro Latini
    Principal Support engineer
    Delphix
    ------------------------------



  • 14.  RE: Unable to disable constraints-Oracle

    Posted 12-05-2022 03:59:00 PM
    Hi Sandro,

    Thanks for advising on this, yes we did consider CM algorithm and as it masks to Gibberish values, which are of no use for business as they need realistic names only.

    Moreover, I am working on this scenario closely with Delphix business partner and we did try almost all available options while referring KBA's & last resort was to opt Postgre SQL DB for Mapping algorithm but luckily removing duplicate names procedure worked for us. So thought to share for other's benefit in case they are/will be in same fuss.

    Regards,
    Raman

    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 15.  RE: Unable to disable constraints-Oracle

    Posted 12-06-2022 12:52:00 AM
    Your issue is simply that you try to use a NON-UNIQUE llogic on a UNIQUE key.
    The names framework is not designed to be unique as names tend to be NEVER unique.
    The is a customisation called MC_NAMES that has the almost identical logic as NAMES but it is using chaining from the core logic to the value replacement.
    The NAME framework uses always SecureLookup (which is never unique). In MC_NAMES you configure the chaining target (which algorithm to use as value replacement) and you can choose MAPPING. Mapping is by definition always unique.
    If you are interested in this (billable) plugin please get in touch with your Delphix customer success or professional services representative.
    Have you tried using a MAPPING algorithm ? Adding numbers 1/2/3/4/... seems to me "glibberish" (as you named it :) )
    When you use pl/sql you have to touch the table twice (one time for masking and one time for pl/sql) and it is not deterministic because the order of the pl/sql processing is not guaranteed to be the same every time.

    ------------------------------
    Tino Pironti
    Masking SME
    Technical Manager
    Delphix
    ------------------------------



  • 16.  RE: Unable to disable constraints-Oracle

    Posted 12-06-2022 05:36:00 AM
    Hi Tino,

    Yes I am using non-unique algorithm (name Secure lookup) for unique (PK/FK) constraint column and it produces duplicate values.

    Seems MC_names, referred above is something which can be a new on-demand (billable) plugin & could be used as regular Algorithm instead of Mapping Algorithm, which requires Postgre SQL to run efficiently? 

    You're right adding no. in front of duplicate names is Gibberish but it makes them unique & that too for a very few duplicates (as the constraint has other 5-6 columns too & if any of the column is unique then there is no need to deduplicate the name column), for e.g., it has contrib no., DOB, initials & Relationship columns as part of constraint along with name column, so if any of the value is unique it allows constraint to work & we just need to resolve duplicate names where all of these columns contain similar values , which is rare & the case with person having twins or triplets only, so this small PL/SQL script to resolve duplicate name is working for us & shouldn't require to get paid plugin.

    As stated earlier we're using pre-sql for disabling the constraints and post-sql to call the PL/SQL procedure and then enable the constraint subsequently, which is tested no. of times and working as expected. Hopefully this trend of successful run should continue when we implement it in PROD environment.

    Please advise if you've other thoughts or more information is required or anything got missed.

    Regards,
    Raman



    ------------------------------
    Raman Gulati
    Data Masking Specialist
    Bupa Australia Pty Ltd.
    ------------------------------



  • 17.  RE: Unable to disable constraints-Oracle

    Posted 12-06-2022 06:52:00 AM
    Edited by Tino Pironti 12-06-2022 06:55:40 AM

    MC_NAMES still needs the external algorithm for value replacements, but it allows to use instead of secure lookup any other String compatible algorithm. NAME framework always uses SecureLookup for value replacement which causes collissions (two inputs mask to same output).

    If a database is 100% normalized and each "name" exists only once in the reference tables and the data tables only use the refernece ID > you need to mask the values in reference table with a uniqueness preserving logic.

    The special of NAME and MC_NAMES framework is that they split the input into "word terms" that get masked individually and they support the concept of particles to be preserved/removed like Mr/Mrs/Dr/Professor/...
    Other frameworks take the entire input string as ONE value:
    SECURE LOOKUP : TOM > PETER and JOHN > JIM and "TOM JOHN" > ANDREW (because "TOM JOHN" is one term)

    NAMES and MC_NAMES : TOM > PETER and JOHN > JIM and "TOM JOHN" > "PETER JIM" (because TOM and JOHN are processed as individual terms)



    ------------------------------
    Tino Pironti
    Masking SME
    Technical Manager
    Delphix
    ------------------------------