Troubleshooting Masking Performance In-Place Generic DB (KBA6409)

SELECT

• The SELECT reads the dataset to be masked.
• The first 10,000 to 20,000 records are normally read fast as the records are read into the masking engine buffers.
• This is usually visible as a performance peak at the start of the job and shows the performance of the SELECT statement.

Masking Transformation  

• The SELECT is usually faster than the masking operation.
• How fast depends on how many algorithms are used and the masked data.

UPDATE

• The last step is UPDATE.
• This is usually the performance bottleneck. 
• The likely causes are the number of blocks/pages accessed and updated and the write performance of the database. 

Performance Graph 

By temporarily setting the Feedback Size = Commit Size to 10,000 and Row Limit = 200,000, the execution can be illustrated in a graph. This graph shows the performance as the buffers fill up and can show where the bottlenecks are located.

An example of this can be seen below, which shows the job in the illustration above. The graph shows the relative performance compared with the RPM of the overall masking job.

The characteristics in this example are: 

• The SELECT performance is initially the max performance that can be fetched from the database. 
• As soon as the records start to appear and are masked they will be sent to the UPDATE step.
• The UPDATE performance is seen as soon as records are available to be updated.
• The SELECT will be at max speed until the initial buffers are full (around 20,000 - 30,0000 rows).
• The performance is then (in this case) capped to the performance of the masking operation.
• When all (relevant) buffers are full the SELECT step will be forced to the same performance as the UPDATE step.

Examples and Actions  

No masking job is the same and the characteristics will differ. With that said, the bottleneck can be identified in one of four different groups based on the bottleneck. 

These are:

Update 

	The SELECT quickly peaks at max performance, then drops by masking operation (duration depends on Row Limit), and then capped by the Update performance.  Database Actions: Investigate all details around UPDATE. Check network and storage latencies. Investigate Triggers, Indexes, and Constraints.
	Signature in the logs: ThroughputLogger:interval 42.43 MB (1204439 rows) counted in 30.000 sec ... at the start fast and then continues slow (here 40 Krpm) ... ThroughputLogger:interval 0.53 MB (20012 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.51 MB (19285 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.52 MB (19663 rows) counted in 30.000 sec ... ... continues ...

Hung Job (DB lock)

	This is technically not a Performance issue - but frequently reported as such since the RPM is dropping (no records masked and the time duration increases). Database Actions: Check for locks on SELECT and/or UPDATE. Check Transaction Logs/Journaling and free space.
	Signature in the logs: ... ThroughputLogger:interval 0.00 MB (0 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.00 MB (0 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.00 MB (0 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.00 MB (0 rows) counted in 30.000 sec ... ... continues ...

Masking operation  

The SELECT quickly peaks at max performance and then is capped by the masking operation. This is rare. If there are a moderate number of OOTB (Out of the Box) algorithms (say 10 per table), this is likely not the issue. Algorithms with RegEx or the old version of the Segment Mapping algorithm (and 5 were used per table) could hit this. Actions: Investigate the number of algorithms, data type, and data size. Check the load on the masking engine.

Signature in the logs (very similar to Update): ThroughputLogger:interval 42.43 MB (1204439 rows) counted in 30.000 sec ... at the start fast and then continues slow (here 40 Krpm) ... ThroughputLogger:interval 0.53 MB (20012 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.51 MB (19285 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.52 MB (19663 rows) counted in 30.000 sec ... ... continues ...

Select  

	This is a rare case. If SELECT is slow, then the performance will not be faster than the Input Step can read data and hence capped on SELECT. Actions: Investigate the Execution Plan for SELECT  Check network latency.
	Signature in the logs: ThroughputLogger:interval 0.53 MB (20012 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.51 MB (19285 rows) counted in 30.000 sec ... ThroughputLogger:interval 0.52 MB (19663 rows) counted in 30.000 sec ... ...  starts slow and continues slow (here 40 Krpm) ...

Network performance   

Ping the Masking Engine and collect latency data. Run this a few times to get a good average value for the latency.

ping Your_Masking_Engine

SELECT COUNT Performance 

This will show how fast the database can count the records in the table. This is usually the max performance as there is no network latency. 

Actions

• Change TABLE to the table to test.
• Take note of the number of records.
• Take note of the duration to complete this statement (in seconds). 

SELECT COUNT(*) AS COUNT_TEST FROM [TABLE]

Database performance estimates 

With the number of records and the duration, the select read performance of all records can be calculated: 

• Count Rows per Minute: RowCount / Duration_Secs * 60

Question

Is the SELECT COUNT performance the same (or close to) the Masking Job Performance?

• Yes - On the database, investigate the root cause as to why reading data in the SELECT COUNT is slow.
• No - keep reading.

SELECT Performance 

The SELECT is here encapsulated in a SELECT COUNT to reduce the output size. The duration is expected to be the same as above. 

Actions

• Change TABLE to the table to test.
• Take note of the number of records.
• Take note of the duration to complete this statement (in seconds). 

SELECT count(*) AS SELECT_TEST FROM (select * from [TABLE]) as tst

Database performance estimates 

With the metadata above, the select fetch performance can be calculated (note that this is the performance on the database and excludes network latency and java processing times): 

• Select Rows per Minute: RowCount / Duration_Secs * 60

UPDATE Performance 

The UPDATE performance is usually slower and a likely bottleneck. This will measure how long time it will take to write the same data as read (out = in). 

Actions:

• Change TABLE to the table to test.
• Change msk1, msk2,... to the masked columns (use as many as being masked).
• Take note of the number of records.
• Take note of the duration to complete this statement (in seconds). 

UPDATE [TABLE] SET msk1 = msk1, msk2 = msk2, ...

Database performance estimates 

With the number of updated records and the duration, the UPDATE performance can be calculated: 

• Update Rows per Minute: RowCount / Duration_Secs * 60

Question

Is the SELECT COUNT performance the same (or close to) the Masking Job Performance?

• Yes -on the database, investigate as to why updating the table is slow.
• No - open a support case.

Table Metadata 

Some data about the table is also useful. 

Actions

• Take note of the table description.
• Take note of any triggers and indexes on the table.
• If possible - collect the number of pages/blocks required to store this table on the database. 

Example Output

The example below is from a small table called 'MyTable'. The SQL to collect this will differ from database to database. 

+-----------+----------+------------+-----------+-------------+
| TableName | RowCount | TotalPages | UsedPages | RowsPerPage |
+-----------+----------+------------+-----------+-------------+
| MyTable   |  509,223 |      1,937 |     1,933 |         263 |
+-----------+----------+------------+-----------+-------------+

Example calculations 

Crunching the numbers above you get the following result.

• The UPDATE is 7.8 times slower than SELECT (650/83).
• The UPDATE performance will cap the performance of the masking job.

+---------------+--------------+----------+----------+---------+
|               |              |    COUNT |   SELECT |  UPDATE |
+---------------+--------------+----------+----------+---------+
|               |     Metadata |    47 ms |    47 ms |  360 ms |
+---------------+--------------+----------+----------+---------+
| Rows per Min  | 509,223 rows | 650 Mrpm | 650 Mrpm | 83 Mrpm |
+---------------+--------------+----------+----------+---------+

More info on how to access logs

• KBA: How to Troubleshoot Masking Jobs and Access Masking Logs (KBA7988)

Casting using SQL

• KBA: Algorithm: Casting Values Before Masking (KBA1580)
• KBA: Using the Custom SQL Rule Set Feature (KBA4455)

Performance recommendations

• KBA: Masking Commit Size, Row Limit and Feedback Size (KBA6387)
• KBA: Best Practice: Masking Performance (Database) (KBA1561)

Troubleshoot Performance in Oracle and MS SQL Server

• KBA: Troubleshooting Masking Performance In-Place Oracle (KBA5985)
• KBA: Troubleshooting Masking Performance In-Place MS SQL Server (KBA6371)