Skip to main content
Delphix

How to Troubleshoot Masking Jobs and Access Masking Logs (KBA7988)

 

KBA

KBA# 7988

At a Glance  

Applicable to: This article is a brief introduction to finding errors on the Masking Engine. It also covers where to find errors and the logs to search.
Logs: Logs, where errors are recorded can be located in a few places on the engine:
  • User Interface: 
    • The Job Monitor (job related errors).
    • Admin page under Logs.
  • API:
    • GET /application-logs
API Logs to collect: There are four different types of logs to collect from the API - in order of importance:
  1. INFO (contains all Errors, Warnings, and Information log entries).
  2. WARNING (contains all Errors and Warnings).
  3. ERROR (contains only Errors).
  4. DEBUG (this is for debugging only). 
Locating Errors: To filter and locate details in the logs, these tools on Linux/Unix and Windows PowerShell will help: 

Linux/Unix
grep

Windows 
Select-String
Activity Audit: Another source to investigate is the activity Audit. This provides details into when and by whom a specific task was performed:
  • User Interface: 
    • Audit page (only accessible to Administrators)
  • API:
    • GET /audit-logs

Applicable Delphix Versions

Click here to view the versions of the Delphix engine to which this article applies
Major Release All Sub Releases
6.0 6.0.0.0, 6.0.1.0, 6.0.1.1, 6.0.2.0, 6.0.2.1, 6.0.3.0, 6.0.3.1, 6.0.4.0, 6.0.4.1, 6.0.4.2, 6.0.5.0, 6.0.6.0, 6.0.6.1, 6.0.7.0, 6.0.8.0, 6.0.8.1, 6.0.9.0

5.3

5.3.0.0, 5.3.0.1, 5.3.0.2, 5.3.0.3, 5.3.1.0, 5.3.1.1, 5.3.1.2, 5.3.2.0, 5.3.3.0, 5.3.3.1, 5.3.4.0, 5.3.5.0, 5.3.6.0, 5.3.7.0, 5.3.7.1, 5.3.8.0, 5.3.8.1, 5.3.9.0

5.2

5.2.2.0, 5.2.2.1, 5.2.3.0, 5.2.4.0, 5.2.5.0, 5.2.5.1, 5.2.6.0, 5.2.6.1

5.1

5.1.0.0, 5.1.1.0, 5.1.2.0, 5.1.3.0, 5.1.4.0, 5.1.5.0, 5.1.5.1, 5.1.6.0, 5.1.7.0, 5.1.8.0, 5.1.8.1, 5.1.9.0, 5.1.10.0

5.0

5.0.1.0, 5.0.1.1, 5.0.2.0, 5.0.2.1, 5.0.2.2, 5.0.2.3, 5.0.3.0, 5.0.3.1, 5.0.4.0, 5.0.4.1, 5.0.5.0, 5.0.5.1, 5.0.5.2, 5.0.5.3, 5.0.5.4

 

How to Troubleshoot 

If there is an error on the Masking Engine, the first action is to determine where the error occurred.

What failed? Was it: 

  • the Execution of a Job?
  • the Configuration of an object such as Algorithm, Rule Set, or Job?
  • a Sync operation?
  • an API call?

Who performed the Actions?

What and where to look

Below are common scenarios and where to look when there is an error or an issue.

Job Execution - Masking Operation

This is the most common scenario. Refer to the steps below to troubleshoot: 

  1. From the User Interface, look in the Job Monitor and identify the Table or File with the error - click on the Error triangle. 
  2. Use the API and access GET /execution-events.

You can also use the steps detailed below in the section "Finding errors in INFO.log for specific JOB". 

Job Execution - Creation, Pre Masking or Post Masking Operations 

Some operations and errors might not be reported in the Execution Events. For troubleshooting these, use the INFO logs.

  • For errors in Job Creation - look for any errors after the job starts:
    • Start by identifying the start of the job by looking for 'Job with execution ID nn submitted'.
    • Look for any errors.
    • If 'JOB_ID_xx_yy ... Start of run.' is not indicated, then the likely root cause is a Queued Job or Out of Memory.
    • If 'Unable to load the job from XML' shows, then the job failed to be created.
       
  • For errors in Pre and Post Masking Operations (such and Drop, Create, Pre, and Post Scripts):

Any other Error

For all other errors:

  • Take note of the Masking Engine time (UTC).
    • Look in the Job Monitor or in the Audit for a timestamp.
  • Then use the INFO logs and the steps detailed in "Finding errors in INFO.log". 

Who performed the action?

To determine who performed an action, look in the activity Audit.

If the issue is not found?

If the issue is not found or there are questions about the issue or the root cause, please contact Delphix Support. 

 

Note

Note:

If the issue pertains to Custom Developed Algorithms or Scripts - please, as a first step, contact the author before contacting Delphix Support. This will ensure prompt response and resolution. And, if any details are needed for a support case, they can be collected.

 

Collecting Logs

Collecting Engine INFO Logs

The logs to collect and investigate on the Engine are the INFO logs. These are available in the Engine User Interface and from the API.

  • User Interface: 
    • Admin page under Logs.
  • API:
    • GET /application-logs
Logs from the API

There are four different types of logs to collect from the API. The most relevant information is found in the INFO log. Other types have been provided but are less important.

Note

Note:

All logs contain one active file (i.e. info.log) and 21 historical copies (examples info.log.1 to info.log.21).

In order of relevance: 

  1. INFO (contains all Errors, Warnings, and Information log entries).
  2. WARNING (contains all Errors and Warnings).
  3. ERROR (contains only Errors). As this contains only ERROR these logs roll less frequently.
  4. DEBUG (this is for debugging only). This log rolls very quickly. 

Collecting activity Audit

To find details about who and when an activity happened, use the activity Audit log. 

 

Note

Notes:

  • The status in this log indicates if the command was successfully 'started'. It is not indicating the status of the command. Hence a Masking Job can fail but in the Audit log will record this as SUCCEEDED as the job was successfully started. If the job failed to start (for example due to incorrect Job ID, then the Audit will show FAILED).
  • The retention for the Audit log is detailed in the Masking Documentation. See the Related Articles section below for the link.

How to access

  • User Interface: 
    • Audit page (only accessible to Administrators)
  • API:
    • GET /audit-logs

An Introduction to Investigating the Logs

When the logs have been downloaded, use these command lines to filter and find errors. 

This shows the most common errors. To filter on additional errors, the filter argument may need to be modified. Error messages do change and all errors are not known and differ from database to database and from access method to access method.

For more information about OS commands - please see the OS documentation or search the Web.

Linux/Unix

Finding errors in INFO.log

This listing can return many matches. See below for how to filter on a specific job and execution. 

grep -E "E=1|ORA-|Masking Engine|IO Error|Caused by|OutOfMemoryError|Job with execution.*submitted|Unable to load the job|Couldn't execute|Failed|updating batch|LoginController|WARNING|for job|Masking Engine" info.log
Finding errors in INFO.log for specific JOB

This limits the search for errors to a specific job and execution (change xx and yy to the job and execution as required). 

grep -E "E=1|ORA-|Masking Engine|IO Error|Caused by|OutOfMemoryError|Job with execution.*submitted|Unable to load the job|Couldn't execute|Failed|updating batch|LoginController|WARNING|for job|Masking Engine" info.log | grep "JOB_ID_xx_yy"

 

Windows PowerShell

Finding errors in INFO.log

This listing can be long. See below on how to filter on a specific job and execution. 

Select-String "E=1|ORA-|Masking Engine|IO Error|Caused by|OutOfMemoryError|Job with execution.*submitted|Unable to load the job|Couldn't execute|Failed|updating batch|LoginController|WARNING|for job|Masking Engine" info.log
Finding errors in INFO.log for specific JOB

This limits the search for errors to a specific job and execution (change xx and yy to the job and execution as required). 

Select-String "E=1|ORA-|Masking Engine|IO Error|Caused by|OutOfMemoryError|Job with execution.*submitted|Unable to load the job|Couldn't execute|Failed|updating batch|LoginController|WARNING|for job|Masking Engine" info.log | Select-String "JOB_ID_xx_yy"

Log Example

Below are some logs and descriptions (slightly modified for readability).

 

Note

Note:

Job Execution logs (JOB_ID_xx_yy) are encapsulated in INFO ...RunServiceImpl. This is because it is this thread that monitors the Job Execution.

  • INFO
    • Indicates general activity such as Login, User Activities, and Creating Jobs etc.
    • INFO also indicates if jobs (or actions) were Successful. 
    • These are important to know to understand actions before or around an issue/error. 
       
  • WARNING
    • There are very few warnings in the logs.
    • The filters above will capture some warnings which are 'Non-Conforming Data' (which is an INFO log entry) (see example below).
       
  • ERROR
    • Logged when there is an ERROR.
       
  • 'Caused by'
    • Caused by is always good to look for as it (usually) captures all errors. 
    • Note that it might not include a timestamp (if not, look for a log entry above).
       
  • 'Masking Engine Version
    • This is logged at the top of each info.log file and each time the engine was rebooted.
    • This is a good way to check the version and if the entry is not at the top, it indicates an engine restart. 
2021-07-21 07:10:49,134 Masking Engine Version: 6.0.9.0....
...
2021-07-27 23:07:29,407 [...-1] INFO  com.dmsuite.web.user.LoginController - Submitting login credential
2021-07-27 23:07:29,704 [...-1] INFO  com.dmsuite.web.user.LoginController - User 5
2021-07-27 23:07:40,148 [...-10] INFO  c.dmsuite.threads.JobExecutorService - Job with execution ID: 47 submitted to thread pool
2021-07-27 23:07:49,718 [...-7] INFO  c.d.d.m.t.RunServiceImpl - [JOB_ID_6_47] WARNING-UNMASKED-DATA: UUID failed to mask data at Tbl_Test.mask: Only 0 characters masked in value (at least 1 required) (1+ occurrences)
...
2021-07-27 23:07:50,520 [...-7] INFO  c.dmsuite.threads.JobExecutorService - [JOB_ID_6_47] - Execution 47 for job 6 completed successfully
...
2021-08-01 23:21:32,602 [...-2] INFO  c.dmsuite.threads.JobExecutorService - Job with execution ID: 58 submitted to thread pool
2021-08-01 23:21:39,235 [...-3] INFO  c.d.d.m.t.RunServiceImpl - [JOB_ID_10_58] 2021/08/01 23:21:39 - DelphixTableUpdate.0 - Error updating batch
2021-08-01 23:21:39,235 [...-3] INFO  c.d.d.m.t.RunServiceImpl - [JOB_ID_10_58] 2021/08/01 23:21:39 - DelphixTableUpdate.0 - ORA-00001: unique constraint (DBO.PK_TBL_PK) violated
2021-08-01 23:21:39,252 [...-3] INFO  c.d.d.m.t.RunServiceImpl - [JOB_ID_10_58] 2021/08/01 23:21:39 - DelphixTableUpdate.0 - Caused by: java.sql.BatchUpdateException: ORA-00001: unique constraint (DBO.PK_TBL_PK) violated
2021-08-01 23:21:39,252 [...-3] INFO  c.d.d.m.t.RunServiceImpl - [JOB_ID_10_58] 2021/08/01 23:21:39 - DelphixTableUpdate.0 - Finished processing (I=2, O=0, R=2, W=1, U=1, E=1)
2021-08-01 23:21:45,978 [...-3] ERROR c.dmsuite.threads.JobExecutorService - [JOB_ID_10_58] - Execution 58 for job 10 failed

 

 

Related Articles

The following articles may provide more information or related information to this article: