Skip to main content
Delphix

Masking Logs - What is IORWUE? (KBA1132)

 

Description of Masking Progress Counters

The difference between the different progress countries can at first look subtle - the key difference between I-R and O-W is if the rows are an Input/Output step in/out from the Masking Job process, or rows Read/Written in and out from  Masking Job steps. 

Counters

The 6 counters are: 

  • 2 x Input/Output Counters (from database, file or another external source)
    • I, O
  • 2 x Stream Process Counters
    • R, W
  • 1 x Update Counter
    • U
  • 1 x Error Counter
    • E

Counter Description 

I - The number of rows been received in from Input into the Masking Job process. 
O - The number of rows been sent out to Output from the Masking Job process.

R - The number of rows been Read in from the previous Masking Job step.
W - The number of rows been Written out from a Masking Job step.

U - The number of rows been Updated by a Masking Job step (this is normally UPDATE database statement).

E - The number of rows which encountered an ERROR in a particular Masking Job step.

Example - Masking Job

The example below is condensed to make it easier to see and is from a Masking Job. 

[JOB_ID_1226_1441] INFO  28-09 23:37:42,731 - Table input - Finished processing (I=9297745, O=0, R=0, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:42,942 - Select values - Finished processing (I=0, O=0, R=9297745, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:43,158 - Get All Lookups Values - Finished processing (I=0, O=0, R=9297745, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:43,162 - Col0_lookUp - Finished processing (I=0, O=0, R=9325608, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:45,752 - Col1_lookUp - Finished processing (I=0, O=0, R=9298747, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:48,949 - Get All Lookups Values For PhoneOrSSN - Finished processing (I=0, O=0, R=9297745, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:51,992 - SelectValues_MetaData - Finished processing (I=0, O=0, R=9297745, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:51,996 - String Cut - Finished processing (I=0, O=0, R=9297745, W=9297745, U=0, E=0)
[JOB_ID_1226_1441] INFO  28-09 23:37:56,571 - Update - Finished processing (I=9297745, O=0, R=9297745, W=9297745, U=9297745, E=0)

We can here see that we have:

  1. Table Input: Input 9,297,745 rows from the database (I=9297745) and Wrote 9,297,745 rows to the next step (W=9297745).
  2. Select values: Read 9,297,745 rows from the previous step (R=9297745) and Wrote 9,297,745 rows (as above).
  3. Get All Lookups Values: Read 9,297,745 rows from the previous step (R=9297745) and Wrote 9,297,745 rows (as above).
    ...
  4. Update:  This step is interesting - here are some observations: 
    • Input 9,297,745 rows (I=9297745).
    • Output 0 rows - this is correct, we did not output any rows as we Updated the rows in the database.
    • Read 9,297,745 rows from the last step (R=9297745).
    • Wrote 9,297,745 rows to the next step (W=9297745) - all step writes data out.
    • Updated 9,297,745 rows in the database (U=9297745).

Example - Masking Job with Error 

The example below is an Error in the Update step - in this example it is caused by a database deadlock.

2017/09/26 19:55:59 - Update.0 - ERROR (ver... ...dguy) : Unable to commit Update connection [GEMFISH_ONYX_REPORTING_CONN] :org.pentaho.di.core.exception.KettleDatabaseBatchException:
2017/09/26 19:55:59 - Update.0 - ERROR (ver... ...dguy) : Error updating batch
2017/09/26 19:55:59 - Update.0 - ERROR (ver... ...dguy) : Transaction (Process ID 79) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
2017/09/26 19:55:59 - Update.0 - Finished processing (I=39, O=0, R=39, W=39, U=39, E=1)

A description of the steps and counters:

  • Input 39 rows (I=39).
  • Read 39 rows (R=39).
  • Wrote 39 rows (W=39).
  • Updated 39 rows (U=39).
  • 1 Error (E=1).

Child jobs to Masking Job - Dropping Indexes, Pre/Post Scripts etc

Execute_Disable_Triggers_Script.0 - Finished processing (I=0, O=0, R=0, W=1, U=0, E=0)
  • All steps: Writes 1 row to the next process.

This is independent from how many SQL statements are being executed.

Troubleshooting

These counters can be used to determine:

  • Masking progress.
  • Masking performance (rows/min).
  • Masking errors (for example Table Input or Update errors).
  • Masking issue (any step holding up the masking process).
  • Algorithm issues (similar to above).