Streams Apply Parameter – commit_serialization
Overview
When using Change Data Capture (CDC) technology, which is based on streams, there are several ways to configure it. I am using the Asynchronous Autolog Archive option which uses archived redo log file shipping and then mines the log for the changes which we require at the downstream capture DB.
We noticed that it was taking approximately 5 minutes to process a 2GB archived log file. I carried out some analysis on where the bottlenecks in the system were by using the package DBMS_STREAMS_ADVISOR_ADM. This package is very useful for analysing the streams configuration and identifying where there are bottlenecks in your configuration.
In essence, you take two snapshots at the times when you want to compare the activity. I took the first snapshot just after registering the log file with the CDC publisher user, and the second one just as the log had finished being mined. I identified this by looking in the alert log for the line “LOGMINER: End mining logfile for…”
Identification of Bottleneck
First of all I executed this code, once at the start and once at the end of the period I wanted to analyse.
BEGIN DBMS_STREAMS_ADVISOR_ADM.ANALYZE_CURRENT_PERFORMANCE; end; /
Next, I ran the following query to determine which snapshot IDs I would need to view and analyse:
SELECT DISTINCT advisor_run_id FROM DBA_STREAMS_TP_COMPONENT_STAT ORDER BY ADVISOR_RUN_ID;
I should also point out at this point that if you have taken two snapshots, the more recent one will compare its findings with the previous one, and this is the one you should look at to cover time period you are interested in. Using the snapshot ID that you want to view from the above output, you add it to the ADVISOR_RUN_ID=4 part below. Change 4 for whichever snapshot ID you want to look at. If this is the first time that you have run it, you will probably be using 2 for the advisor run ID number.
COLUMN PATH_ID HEADING 'Path ID' FORMAT 999 COLUMN COMPONENT_ID HEADING 'Component ID' FORMAT 999 COLUMN COMPONENT_NAME HEADING 'Name' FORMAT A20 COLUMN COMPONENT_TYPE HEADING 'Type' FORMAT A20 COLUMN COMPONENT_DB HEADING 'Database' FORMAT A15 SELECT PATH_ID, COMPONENT_ID, COMPONENT_NAME, COMPONENT_TYPE, COMPONENT_DB FROM DBA_STREAMS_TP_PATH_BOTTLENECK WHERE BOTTLENECK_IDENTIFIED='YES' AND ADVISOR_RUN_ID=4 ORDER BY PATH_ID, COMPONENT_ID;
This will show you if the analyse job found any components which were considered as bottlenecks. In my case, I found out that the APPLY process was the bottleneck.
Using the COMPONENT_ID shown in the query above, substitute the numbers in the line “AND cs.component_id in (3,4)” in the query below and execute the query to identify the wait events for that component.
In addition, you will have to make sure that the ADVISOR_RUN_ID is the correct number as you found out previously.
Note: I have component_ids 3 and 4 in the query because I have two apply processes. It will all depend upon how which components you are looking at and how many of them there are.
SELECT DISTINCT cp.PATH_ID, cs.COMPONENT_ID, cs.COMPONENT_NAME, cs.COMPONENT_TYPE, cs.STATISTIC_NAME, cs.STATISTIC_VALUE, cs.STATISTIC_UNIT FROM DBA_STREAMS_TP_COMPONENT_STAT cs, (SELECT PATH_ID, SOURCE_COMPONENT_ID AS COMPONENT_ID FROM DBA_STREAMS_TP_COMPONENT_LINK UNION SELECT PATH_ID, DESTINATION_COMPONENT_ID AS COMPONENT_ID FROM DBA_STREAMS_TP_COMPONENT_LINK) cp WHERE cs.ADVISOR_RUN_ID = 4 AND cs.SESSION_ID IS NULL AND cs.SESSION_SERIAL# IS NULL AND cs.COMPONENT_ID = cp.COMPONENT_ID AND cs.component_id IN (3,4) ORDER BY PATH_ID, COMPONENT_ID, COMPONENT_NAME, COMPONENT_TYPE, STATISTIC_NAME;
The results of the above query show various, interesting metrics. For example, the MESSAGE APPLY RATE and LATENCY. In my case, I could also see the cause of the bottleneck, it was “EVENT: Streams apply: waiting to commit”. Very interesting.
The Cause
Looking this error up showed that because I had the apply parallelism set higher than 1, my apply processes were waiting for one another to commit transactions to the change tables. The reason they were waiting for one another was because I had the parameter COMMIT_SERIALIZATION to set to FULL. This means that every transaction has to be committed in the correct order in the change tables, or whatever downstream process you have, when compared to the order in which it was committed at the source DB.
The Solution
There is another option…You don’t necessarily have to make sure that all the changes are committed in the exact order. The reason for this setting, I assume, is so that if you have real time apply and also subscribers reading this data as it’s being applied, you probably want to have this setting turned on. However, in my case we are not doing that. We are applying the log in full and then processing that set of data, so we can change the setting of COMMIT_SERIALIZATION from FULL to DEPENDENT_TRANSACTIONS. This ensures that dependent transactions are applied in the correct order, otherwise there could be issues, but all other transactions can commit as they are being applied so long as there are no dependencies between them.
Making this change and then applying logs now takes less than 2 minutes compared to up to 5 minutes as seen previously. And, re-running the analyzer shows that there are no waits for the “EVENT: Streams apply: waiting to commit”.
Problem solved…For now!
You may find that you are getting stuck with a message Waiting for Dictionary Redo in the V$STREAMS_CAPTURE view, which I have also written about. Or perhaps the ORA-01372: Insufficient processes for specified LogMiner operation. I have written about these errors and many more on this website, so have a look at the links on the left under “Change Data Capture”.
Like it, share it...
Category: Change Data Capture