Skip to content

CDC side effects: which CDC method does not kill performance of transactional Oracle instance

averemee-si edited this page Mar 22, 2021 · 1 revision

Imagine that you have a highly loaded transactional system, you do not have the ability to change the application, your equipment scalability is limited, but you need to add new functionality. CDC may help with creation of replica for new functionality, but how to get changed data from transactional Oracle instance? Let's do an testing. We will use a simple table

drop table TEST_WRITE_OPS;
create table TEST_WRITE_OPS(
  TEST_ID NUMBER(10) not null,
  TEST_CHARS varchar2(4000) not null,
  TEST_DATE date not null,
  constraint TEST_WRITE_OPS_PK primary key(TEST_ID) using index tablespace TESTDATA)
tablespace TESTDATA;

, we will insert 1 million records into it

declare
	l_record_count pls_integer;
begin
	l_record_count := 0;
	for l_recno in 1..1000000 loop
		insert into TEST_WRITE_OPS(TEST_ID, TEST_CHARS, TEST_DATE)
		values(l_recno, DBMS_RANDOM.string('L', 255), SYSDATE);
		l_record_count := l_record_count + 1;
		if (l_record_count > 5000) then
			commit;
			l_record_count := 0;
		end if;
	end loop;
	commit;
end;
/

, and we will receive information about changed data in three different ways:

  1. using supplemental logging for using LogMiner
  2. Materialized View Logs (I remember times when these was called snapshot logs)
  3. Transactional Event Queues (Not too long ago it was just called Advanced Queuing).

For measuring timing we will use the following commands

alter session set tracefile_identifier = 'OVERHEAD';
alter session set max_dump_file_size = unlimited;
alter session set events '10046 trace name context forever, level 8';
set timing on

Let start with "pure" insert without any additional setting for CDC: create table and insert records:

Elapsed: 00:08:05.01
...
...
...
INSERT INTO TEST_WRITE_OPS(TEST_ID, TEST_CHARS, TEST_DATE) 
VALUES
(:B1 , DBMS_RANDOM.STRING('L', 255), SYSDATE)
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 1000000    377.09     402.88        173      41181    3965154     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1000001    377.09     402.88        173      41181    3965154     1000000

Continue with 1) - using supplemental logging for using LogMiner, drop and create again table and modify it with:

alter table TEST_WRITE_OPS add supplemental log data (ALL) columns; 

then again insert 1 million rows:

Elapsed: 00:08:05.47
...
...
INSERT INTO TEST_WRITE_OPS(TEST_ID, TEST_CHARS, TEST_DATE) 
VALUES
(:B1 , DBMS_RANDOM.STRING('L', 255), SYSDATE)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 1000000    372.82     400.98        179      41291    3965179     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1000001    372.82     400.98        179      41291    3965179     1000000

Same as our "pure" run, no side effect!

Continue with 2) Materialized View Logs, drop and create again table and add snapshot log with:

create materialized view log on TEST_WRITE_OPS
  with primary key, sequence
  excluding new values;

again insert 1 million rows:

Elapsed: 00:13:35.45
...
...
INSERT INTO TEST_WRITE_OPS(TEST_ID, TEST_CHARS, TEST_DATE) 
VALUES
(:B1 , DBMS_RANDOM.STRING('L', 255), SYSDATE)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 1000000    588.65     638.61        231      41739    3968428     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1000001    588.65     638.61        231      41739    3968428     1000000

As expected - the result is 50% worse comparing with table with supplemental logging

Finally - Transactional Event Queues and more setup required after recreation of our test table:

grant AQ_ADMINISTRATOR_ROLE to SCOTT;
grant execute on DBMS_AQ to SCOTT;
grant execute on DBMS_AQADM to SCOTT;

begin
	DBMS_AQADM.CREATE_SHARDED_QUEUE(
		queue_name => 'SCOTT.AQ_TEST_WRITE_OPS',
		multiple_consumers => FALSE,
		queue_payload_type => DBMS_AQADM.JMS_TYPE);
	DBMS_AQADM.START_QUEUE(queue_name => 'SCOTT.AQ_TEST_WRITE_OPS');
end;
/

create or replace trigger TEST_WRITE_OPS_T
  before insert on TEST_WRITE_OPS
  for each row
declare
  msg SYS.AQ$_JMS_TEXT_MESSAGE;
  queue_options DBMS_AQ.ENQUEUE_OPTIONS_T;
  msg_props DBMS_AQ.MESSAGE_PROPERTIES_T;
  msg_id RAW(16);
begin
  msg := SYS.AQ$_JMS_TEXT_MESSAGE.CONSTRUCT();
  msg.set_text(to_char(:new.TEST_ID));
  DBMS_AQ.ENQUEUE( queue_name => 'SCOTT.AQ_TEST_WRITE_OPS'
                 , enqueue_options => queue_options
                 , message_properties => msg_props
                 , payload => msg
                 , msgid => msg_id);
end;
/

again insert 1 million rows:

Elapsed: 00:20:15.88
...
...
INSERT INTO TEST_WRITE_OPS(TEST_ID, TEST_CHARS, TEST_DATE) 
VALUES
(:B1 , DBMS_RANDOM.STRING('L', 255), SYSDATE)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute 1000000    732.17     811.81        546      43197    3968568     1000000
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   1000001    732.17     811.81        546      43197    3968568     1000000

Worst result, more than three times worse than using supplemental logging

Conclusions

  1. For minimising side effects on performance while capturing changed data you must use supplemental logging and LogMiner. But using this type of capturing data produces new problem: NRT with getting changed data from archived redo is more near than real-time
  2. I got proof again that Transactional Event Queues is not designed for CDC, it designed to decouple in event driven architecture