We are using Oracle 11.2.0.4.0. We created a procedure to do update a CLOB column in a table for all available rows.
We have a DBMS_OUTPUT.PUT_LINE statement to print SYSDATE at the very last line of the Procedure.
When we execute this procedure, it takes long time to complete after the last line has printed the SYSDATE.
Not sure if I am missing anything. Any help would be much appreciated
We tried executing the procedure by having DBMS_OUPUT.PUT_LINE(SYSDATE) statements inside the procedure to debug/find the pain points.
This is how we executed the procedure and pasted the output at the end:
SET TIMING ON
SET SERVEROUTPUT ON
SELECT 'Outside block Start time: ' || to_char(SYSDATE, 'DD-MON-YYYY HH24:MI:SS') OUTSIDEBLOCKSTARTTIME from dual;
DECLARE
I_LIMIT BINARY_INTEGER;
I_STR_TO_REPLACE VARCHAR2(200);
I_REPLACEMENT_STR VARCHAR2(200);
BEGIN
I_LIMIT := 10000;
I_STR_TO_REPLACE := 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890';
I_REPLACEMENT_STR := 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890';
P_TEST_CLOB_MASK(
I_LIMIT => I_LIMIT,
I_STR_TO_REPLACE => I_STR_TO_REPLACE,
I_REPLACEMENT_STR => I_REPLACEMENT_STR
);
END;
/
SELECT 'Outside block End time: ' || to_char(SYSDATE, 'DD-MON-YYYY HH24:MI:SS') OUTSIDEBLOCKENDTIME from dual;
Below is the code for Procedure:
CREATE OR REPLACE PROCEDURE p_test_clob_mask (
i_limit IN PLS_INTEGER DEFAULT 1000,
i_str_to_replace IN VARCHAR2
DEFAULT 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890',
i_replacement_str IN VARCHAR2
DEFAULT 'ABCDEFGHIJKLMNOPQRSTUVWXYZabcdefghijklmnopqrstuvwxyz1234567890'
)
IS
CURSOR cur_fetch_cddaddcomphistory
IS
SELECT ROWID row_id, ua4cf_cddaddcomphistory ua4cf_cddaddcomphistory
FROM generic_set11
WHERE ua4cf_cddaddcomphistory IS NOT NULL;
l_limit NUMBER := 0;
l_counter NUMBER := 0;
l_rowid ROWID;
l_hold_clob CLOB;
l_masked_clob CLOB;
l_length_clob NUMBER := 0;
l_str_to_replace VARCHAR2 (500);
l_replacement_str VARCHAR2 (500);
l_overall_start_dt DATE;
l_batch_start_dt DATE := NULL;
l_batch_time_taken NUMBER := 0;
l_overall_time_taken NUMBER := 0;
BEGIN
l_overall_start_dt := SYSDATE;
DBMS_OUTPUT.put_line ( 'Overall Start: '
|| TO_CHAR (l_overall_start_dt,
'DD-MON-RR HH24:MI:SS'
)
);
l_str_to_replace := i_str_to_replace;
l_replacement_str := i_replacement_str;
l_limit := i_limit;
OPEN cur_fetch_cddaddcomphistory;
LOOP
FETCH cur_fetch_cddaddcomphistory
INTO l_rowid, l_hold_clob;
EXIT WHEN cur_fetch_cddaddcomphistory%NOTFOUND;
l_counter := l_counter + 1;
l_length_clob := DBMS_LOB.getlength (l_hold_clob);
DBMS_LOB.createtemporary (l_masked_clob, TRUE);
DBMS_LOB.writeappend (l_masked_clob,
l_length_clob,
TRANSLATE (l_hold_clob,
i_str_to_replace,
i_replacement_str
)
);
UPDATE generic_set11
SET ua4cf_cddaddcomphistory = l_masked_clob
WHERE ROWID = l_rowid;
IF MOD (l_counter, l_limit) = 0
THEN
COMMIT;
END IF;
END LOOP;
CLOSE cur_fetch_cddaddcomphistory;
COMMIT;
l_overall_time_taken :=
TRUNC (((SYSDATE - l_overall_start_dt) * 24 * 60), 2);
DBMS_OUTPUT.put_line ( 'Overall End: '
|| TO_CHAR (SYSDATE, 'DD-MON-RR HH24:MI:SS')
|| ' - Time taken in Mins: '
|| l_overall_time_taken
|| ' - Counters: '
|| l_counter
);
END p_test_clob_mask;
/
Our expectation is that after the last DBMS_OUPUT.PUT_LINE is completed, the procedure should complete.
But the Elapsed time says 20+ minutes, where as per the last DBMS_OUPUT.PUT_LINEstatement, the time taken was only 3 Minutes
Below is the output:
OUTSIDEBLOCKSTARTTIME
-------------------------------------------------------
Outside block Start time: 27-DEC-2018 15:33:45
Elapsed: 00:00:00.118
Overall Start: 27-DEC-18 15:33:45
Overall End: 27-DEC-18 15:37:37 - Time taken in Mins: 3.86 - Counters: 138913
PL/SQL procedure successfully completed.
Elapsed: 00:20:19.313
OUTSIDEBLOCKENDTIME
-----------------------------------------------------
Outside block End time: 27-DEC-2018 15:54:04
Elapsed: 00:00:00.095
From the comments, the fix was to add the line
DBMS_LOB.freetemporary(l_masked_clob);
at the end of the loop. This ensures that the temporary CLOBs used are cleaned up as they are used. The code as written causes Oracle to create a new temporary CLOB for each iteration of the loop, and it is likely that the cleanup of all of these temporary CLOBs (possibly hundreds or even thousands of them) at the end of the block is causing the delay.
Another possible performance boost could be obtained by creating one temporary LOB outside of the loop, clearing it (e.g. using DBMS_LOB.erase or DBMS_LOB.trim) at the end of each iteration of the loop, and freeing it at the end.