Skip to main content
Delphix

Masking Logs: What is IORWUE? (KBA1132)

 

 

KBA

KBA#1132

At a Glance  

Description: This KBA describes the functionality of the job counters labeled: I O R W U and E.
Affects versions: This KBA applies to all Masking Versions.
 
Log format:
[Step X] - Finished processing (I=n1, O=n2, R=n3, W=n4, U=n5, E=n6)
Counters: The counters are:
  • I -Input Counter, from an external database or file.
  • O -Output Counter, to an external database or file.
  • R -Read Counter, rows read into this masking step.
  • W -Write Counter, rows written out from this masking step.
  • U -Update Counter, rows updated on an external database (In-Place database job).
  • E -Error Counter (flag). E=0 (no error). If the step had an error, then the value is E=1.
More info:  KBAHow to Troubleshoot Masking Jobs and Access Masking Logs (KBA7988)

Masking Job Counters

The difference between the different progress counters can at first look subtle - there are some key differences. 

Details

Log Format

The format in the log files are as follows: 

[Step X] - Finished processing (I=n1, O=n2, R=n3, W=n4, U=n5, E=n6)

The Counters

There are 6 counters: 

  • Input/Output
    • I -Input Counter. This is in from an external database or file.
    • O -Output Counter. This is out to an external database or file.
       
  • Read/Write
    • R -Read Counter. This is the number of rows Read into the step in the masking process.
    • W -Write Counter. This is the number of rows Written (out) from the step in the masking process.
       
  • Update 
    • U -Update Counter. This is updated rows out to an external database. Used only in In-Place database job.
       
  • Error Counter (Flag)
    • E -Error Counter. This is a flag. The default value is 0 (no error). If the step had an error, then the value is E=1.

Example

In-Place DB Masking Job

Final counters in an In-Place database masking job. The example below uses Secure Lookup v1 (this to show Input from both database and file in the same job). 

[JOB_ID_x_y] 0000/00/00 00:00:00 - DelphixTableInput.0 - Finished processing (I=150000, O=0, R=0, W=150000, U=0, E=0)
[JOB_ID_x_y] 0000/00/00 00:00:00 - Select values.0 - Finished processing (I=0, O=0, R=150000, W=150000, U=0, E=0)
...
[JOB_ID_x_y] 0000/00/00 00:00:00 - Col0_dataFromXML.0 - Finished processing (I=124, O=0, R=0, W=124, U=0, E=0)
[JOB_ID_x_y] 0000/00/00 00:00:00 - Col0_lookUp.0 - Finished processing (I=0, O=0, R=150124, W=150000, U=0, E=0)
...
[JOB_ID_x_y] 0000/00/00 00:00:00 - String Cut - Finished processing (I=0, O=0, R=150000, W=150000, U=0, E=0)
[JOB_ID_x_y] 0000/00/00 00:00:00 - DelphixTableUpdate.0 - Finished processing (I=150000, O=0, R=150000, W=150000, U=150000, E=0)

We can here see that we have:

  1. DelphixTableInput:
    • I=150000 - Input 150,000 rows from the database
    • W=150000 - Wrote 150,000 rows to the next step.
  2. Select values:
    • R=150000 - Read 150,000 rows from the previous step.
    • W=150000 - Wrote 150,000 rows to the next step.
      ...
  3. Col0_dataFromXML
    • I=124 - Input 124 (Secure Lookup) values from XML file.
    • W=124 - Wrote rows to the next step.
  4. Col0_lookUp: (Since two streams merge in this step the counts are aggregated).
    • R=150124 - Read 150,000 and 124 rows from previous steps (Select values and Col0_dataFromXML).
    • W=150000 - Wrote 150,000 rows to the next step.
      ...
  5. Update:  some interesting observations: 
    • I=150000 - Input 150,000 rows from the databases (this data is not transferred to the engine but read to update the value).
    • O=0 - Output 0 rows - this is correct, we did not output any rows as we Updated the rows in the database.
    • R=150000 - Read 150,000 rows from the last step.
    • W=150000 - Wrote 150,000 rows - all rows written out.
    • U=150000 - Updated 150,000 rows in the database.

 

Note: The number of rows masked (processed) is the same from Input, through the masking process (exception for lookups where Input is aggregated), to the Update.

Masking Job with Error 

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

[JOB_ID_x_y] 0000/00/00 00:00:00 - DelphixTableUpdate.0 - ORA-00001: unique constraint (xzy) violated
[JOB_ID_x_y] 0000/00/00 00:00:00 - DelphixTableUpdate.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).

Pre/Post SQL Scripts

[JOB_ID_x_y] 0000/00/00 00:00:00 - 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 always 1 independent on how many statements are 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.