-
April 2024 (3)
-
January 2024 (1)
-
October 2023 (1)
-
September 2023 (3)
-
August 2023 (1)
-
June 2023 (1)
-
April 2023 (3)
-
March 2023 (2)
-
February 2023 (1)
-
January 2023 (1)
-
December 2022 (2)
-
October 2022 (2)
-
September 2022 (2)
-
August 2022 (2)
-
July 2022 (1)
-
June 2022 (1)
-
May 2022 (2)
-
April 2022 (2)
-
March 2022 (1)
-
February 2022 (2)
-
January 2022 (1)
-
December 2021 (1)
-
November 2021 (1)
-
October 2021 (2)
-
July 2021 (1)
-
June 2021 (1)
-
May 2021 (1)
-
April 2021 (3)
-
March 2021 (2)
-
January 2021 (1)
-
November 2020 (3)
-
September 2020 (1)
-
August 2020 (1)
-
May 2020 (3)
-
April 2020 (3)
-
February 2020 (2)
-
January 2020 (1)
-
December 2019 (2)
-
August 2019 (2)
-
April 2019 (1)
-
November 2018 (5)
- Oracle row cache objects Event: 10222, Dtrace Script (I)
- Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-1) (II)
- Row Cache Objects, Row Cache Latch on Object Type: Plsql vs Java Call (Part-2) (III)
- Row Cache and Sql Executions (IV)
- Latch: row cache objects Contentions and Scalability (V)
-
October 2018 (2)
-
July 2018 (3)
-
April 2018 (1)
-
March 2018 (2)
-
February 2018 (1)
-
January 2018 (4)
-
October 2017 (2)
-
September 2017 (2)
-
July 2017 (3)
-
May 2017 (8)
- JDBC, Oracle object/collection, dbms_pickler, NOPARALLEL sys.type$ query
- PLSQL Context Switch Functions and Cost
- Oracle Datetime (1) - Concepts
- Oracle Datetime (2) - Examples
- Oracle Datetime (3) - Assignments
- Oracle Datetime (4) - Comparisons
- Oracle Datetime (5) - SQL Arithmetic
- Oracle Datetime (6) - PLSQL Arithmetic
-
March 2017 (3)
-
February 2017 (1)
-
January 2017 (1)
-
November 2016 (1)
-
September 2016 (2)
-
August 2016 (1)
-
June 2016 (1)
-
May 2016 (1)
-
April 2016 (1)
-
February 2016 (1)
-
January 2016 (3)
-
December 2015 (1)
-
November 2015 (1)
-
September 2015 (2)
-
August 2015 (1)
-
July 2015 (2)
-
June 2015 (1)
-
April 2015 (2)
-
January 2015 (1)
-
December 2014 (1)
-
November 2014 (2)
-
May 2014 (3)
-
March 2014 (2)
-
November 2013 (3)
-
September 2013 (1)
-
June 2013 (2)
-
April 2013 (2)
-
March 2013 (3)
-
December 2012 (1)
-
November 2012 (2)
-
July 2012 (1)
-
May 2012 (1)
-
April 2012 (1)
-
February 2012 (1)
-
November 2011 (2)
-
July 2011 (1)
-
May 2011 (3)
-
April 2011 (1)
On Oracle
Thursday, April 18, 2024
Oracle AQ Dequeue 'KTC latch subh' Memory Leak and Dequeue Long Running Test
Following previous Blog: "Oracle dbms_aq.dequeue_array Shared Pool "KTC Latch Subh" Memory Leak"
(http://ksun-oracle.blogspot.com/2021/11/oracle-dbmsaqdequeuearray-shared-pool.html),
we will reproduce another case of AQ Dequeue 'KTC latch subh' Memory Leak test in Orale 19.11
with Patch 31666684, and shows dequeue long (hours) running.
Note: Tested in 19.11 with following DB settings:
We open 3 Sqlplus sessions.
In SID-1, we enqueue 1e6 messages with commit.
In SID-2, dequeue all 1e6 messages without commit to observe 'KTC latch subh' Memory Leak.
Then in SID-3, dequeue one portion (1e3) of messages to show dequeue long running.
We can see 7 hours long dequeue by:
Note: Tested in 19.11 with following DB settings:
Patch 31666684 (Patch Description: MEMORY LEAK KTC LATCH SUBH ON AQ DEQUEUE)
-- set small shared_pool to observe memory resize between shared pool and buffer cache due to "KTC latch subh"
alter system set shared_pool_size=1008M scope=spfile;
-- set 3 subpools in shared_pool
alter system set "_kghdsidx_count"=3 scope=spfile;
-- disable autosga to generate ORA-04031
--alter system set "_memory_imm_mode_without_autosga"=false;
1. Test Setup
drop type k.t_test_obj force;
create or replace noneditionable type k.t_test_obj is object (id integer, type_id integer);
/
begin sys.dbms_aqadm.drop_queue_table(queue_table => 'K.Q_TEST_TAB', force=> TRUE); end;
/
begin
sys.dbms_aqadm.create_queue_table
( queue_table => 'K.Q_TEST_TAB'
,queue_payload_type => 'K.T_TEST_OBJ'
,compatible => '10.0.0' --'8.1'
,storage_clause => 'nocompress
tablespace u1'
,sort_list => 'PRIORITY,ENQ_TIME'
,multiple_consumers => false
,message_grouping => 0
,comment => 'MEMORY LEAK KTC LATCH SUBH AQ test'
,secure => false
);
end;
/
begin
sys.dbms_aqadm.stop_queue (queue_name => 'K.TEST_QUEUE');
sys.dbms_aqadm.drop_queue (queue_name => 'K.TEST_QUEUE');
end;
/
begin
sys.dbms_aqadm.create_queue
( queue_name => 'K.TEST_QUEUE'
,queue_table => 'K.Q_TEST_TAB'
,queue_type => sys.dbms_aqadm.normal_queue
,max_retries => 100
,retry_delay => 2
,retention_time => 604800
,comment => 'AQ Queue Test'
);
end;
/
begin sys.dbms_aqadm.start_queue(queue_name => 'K.TEST_QUEUE', enqueue => true, dequeue => true); end;
/
create or replace procedure test_enq(p_cnt number := 1, p_sleep number := 0) as
l_enqueue_options dbms_aq.enqueue_options_t;
l_message_properties dbms_aq.message_properties_t;
l_message_handle raw(16);
l_msg t_test_obj;
begin
--visibility:
-- dbms_aq.immediate: no commit is required, message is enqueued and committed for dequeue immediately in an autonomous transaction.
-- dbms_aq.on_commit (default): commit is required, message is visibile for dequeue after COMMIT. enqueue session has an open transaction before commit.
--l_enqueue_options.visibility := dbms_aq.immediate;
for i in 1..p_cnt loop
l_msg := t_test_obj(i, 2);
dbms_aq.enqueue(queue_name => 'K.TEST_QUEUE',
enqueue_options => l_enqueue_options,
message_properties => l_message_properties,
payload => l_msg,
msgid => l_message_handle);
--commit; -- no commit
if p_sleep > 0 then
dbms_lock.sleep(p_sleep);
end if;
end loop;
end;
/
create or replace procedure test_deq(p_cnt number := 1, p_dur number := 0, p_sleep number := 0) as
l_dequeue_options dbms_aq.dequeue_options_t;
l_message_properties dbms_aq.message_properties_t;
l_message_handle raw(16);
l_msg t_test_obj;
l_cnt number := 0;
begin
for i in 1..p_cnt loop
begin
l_dequeue_options.wait := p_dur;
if p_sleep > 0 then
dbms_lock.sleep(p_sleep);
end if;
dbms_aq.dequeue(queue_name => 'K.TEST_QUEUE',
dequeue_options => l_dequeue_options,
message_properties => l_message_properties,
payload => l_msg,
msgid => l_message_handle);
--dbms_output.put_line ('id = ' || l_msg.id || ', type_id = ' || l_msg.type_id);
--commit; -- no commit
l_cnt := l_cnt + 1;
exception when others then null;
end;
end loop;
dbms_output.put_line ('l_cnt = ' || l_cnt);
end;
/
-- purge queue for repeated test
declare
po dbms_aqadm.aq$_purge_options_t;
begin
dbms_aqadm.purge_queue_table('K.Q_TEST_TAB', null, po);
end;
/
2. Test Run
We open 3 Sqlplus sessions.
In SID-1, we enqueue 1e6 messages with commit.
In SID-2, dequeue all 1e6 messages without commit to observe 'KTC latch subh' Memory Leak.
Then in SID-3, dequeue one portion (1e3) of messages to show dequeue long running.
3.1. Queue Filling: SID-1 Enueue with commit
SQL > exec test_enq(1e6);
Elapsed: 00:01:55.93
commit;
SQL > select segment_name, segment_type, bytes from dba_segments where segment_name like '%Q_TEST_TAB%';
SEGMENT_NAME SEGMENT_TYPE BYTES
-------------------- ------------------ ----------
Q_TEST_TAB TABLE 125829120
AQ$_Q_TEST_TAB_T INDEX 65536
AQ$_Q_TEST_TAB_I INDEX 51380224
SQL > select count(*) from q_test_tab;
COUNT(*)
----------
1000000
3.2. AQ Dequeue 'KTC latch subh' Memory Leak: SID-2 Dequeue without commit
SQL > select round(bytes/1024/1024, 2) mb, t.* from v$sgastat t where pool='shared pool' and name = 'KTC latch subh';
MB POOL NAME BYTES
---- ----------- -------------- ------
.04 shared pool KTC latch subh 46992
SQL > exec test_deq(1e6);
l_cnt =1000000
PL/SQL procedure successfully completed.
Elapsed: 01:26:32.57
SQL > select round(bytes/1024/1024, 2) mb, t.* from v$sgastat t where pool='shared pool' and name = 'KTC latch subh';
MB POOL NAME BYTES
---- ----------- -------------- -------------
992 shared pool KTC latch subh 1,039,969,240
We can list all SGA memory resize operations:
SQL > select component, parameter, oper_type, initial_size, final_size, final_size-initial_size delta, start_time, end_time
from v$memory_resize_ops where parameter in ('db_cache_size', 'shared_pool_size') order by start_time, parameter;
COMPONENT PARAMETER OPER_TYPE INITIAL_SIZE FINAL_SIZE DELTA START_TI END_TIME
--------------------- ----------------- ---------- -------------- ---------------- -------------- -------- --------
DEFAULT buffer cache db_cache_size STATIC 0 2,097,152,000 2,097,152,000 13:46:14 13:46:14
shared pool shared_pool_size STATIC 0 1,056,964,608 1,056,964,608 13:46:14 13:46:14
DEFAULT buffer cache db_cache_size SHRINK 2,097,152,000 2,080,374,784 -16,777,216 14:31:36 14:31:36
shared pool shared_pool_size GROW 1,056,964,608 1,073,741,824 16,777,216 14:31:36 14:31:36
DEFAULT buffer cache db_cache_size SHRINK 2,080,374,784 2,063,597,568 -16,777,216 14:32:37 14:32:37
shared pool shared_pool_size GROW 1,073,741,824 1,090,519,040 16,777,216 14:32:37 14:32:37
DEFAULT buffer cache db_cache_size SHRINK 2,063,597,568 2,046,820,352 -16,777,216 14:33:41 14:33:41
shared pool shared_pool_size GROW 1,090,519,040 1,107,296,256 16,777,216 14:33:41 14:33:41
.....
shared pool shared_pool_size GROW 1,694,498,816 1,711,276,032 16,777,216 15:34:06 15:34:06
DEFAULT buffer cache db_cache_size SHRINK 1,442,840,576 1,426,063,360 -16,777,216 15:36:18 15:36:18
shared pool shared_pool_size GROW 1,711,276,032 1,728,053,248 16,777,216 15:36:18 15:36:18
DEFAULT buffer cache db_cache_size SHRINK 1,426,063,360 1,409,286,144 -16,777,216 15:38:33 15:38:33
shared pool shared_pool_size GROW 1,728,053,248 1,744,830,464 16,777,216 15:38:33 15:38:33
DEFAULT buffer cache db_cache_size SHRINK 1,409,286,144 1,392,508,928 -16,777,216 15:41:14 15:41:14
shared pool shared_pool_size GROW 1,744,830,464 1,761,607,680 16,777,216 15:41:14 15:41:14
88 rows selected.
There are 42 resize operations from 14:31:36 to 15:41:14, each time shift 16MB from DEFAULT buffer cache to shared pool.
The memory changes are:
shared_pool_size GRO 1,008M -> 1,680M
db_cache_size SHR 2,000M -> 1,328M
KTC latch subh 0M -> 992M
By the way, we can observe many ORA-04031 errors if disable SGA auto resize with:
-- disable autosga to generate ORA-04031
alter system set "_memory_imm_mode_without_autosga"=false;
3.3. Dequeue Long Running: SID-3 Dequeue
We can see 7 hours long dequeue by:
SQL > exec test_deq(1e3);
l_cnt =0
PL/SQL procedure successfully completed.
Elapsed: 07:51:02.15
If we trace SID-3, they are all about 'db file sequential read' on file#=3 (UNDO file) to construct CR block of AQ Queue messages.
PARSING IN CURSOR #139862144662288 len=587 dep=1 uid=0 oct=3 lid=0 tim=25914746826315 hv=3930832701 ad='7f7cb148' sqlid='1y072amp4rgtx'
select /*+ INDEX(TAB AQ$_Q_TEST_TAB_I) */ tab.rowid, tab.msgid, tab.corrid, tab.priority, tab.delay, tab.expiration ,tab.retry_count,
tab.exception_qschema, tab.exception_queue, tab.chain_no, tab.local_order_no, tab.enq_time, tab.time_manager_info, tab.state,
tab.enq_tid, tab.step_no, tab.sender_name, tab.sender_address, tab.sender_protocol, tab.dequeue_msgid, tab.user_prop, tab.user_data
from "K"."Q_TEST_TAB" tab where q_name = :1 and (state = :2 ) order by q_name, state, priority, enq_time, step_no, chain_no,
local_order_no for update skip locked
END OF STMT
EXEC #139862144662288:c=12383,e=39484,p=4,cr=55,cu=0,mis=1,r=0,dep=1,og=1,plh=1032419615,tim=25914746866093
WAIT #139862144662288: nam='db file sequential read' ela= 5849 file#=3 block#=621 blocks=1 obj#=0 tim=25914746872095
WAIT #139862144662288: nam='db file sequential read' ela= 5476 file#=3 block#=620 blocks=1 obj#=0 tim=25914746877756
WAIT #139862144662288: nam='db file sequential read' ela= 11281 file#=3 block#=619 blocks=1 obj#=0 tim=25914746889170
WAIT #139862144662288: nam='db file sequential read' ela= 5466 file#=3 block#=618 blocks=1 obj#=0 tim=25914746894797
WAIT #139862144662288: nam='db file sequential read' ela= 5655 file#=3 block#=617 blocks=1 obj#=0 tim=25914746900588
WAIT #139862144662288: nam='db file sequential read' ela= 5374 file#=3 block#=616 blocks=1 obj#=0 tim=25914746906117
WAIT #139862144662288: nam='db file sequential read' ela= 5522 file#=3 block#=615 blocks=1 obj#=0 tim=25914746911793
WAIT #139862144662288: nam='db file sequential read' ela= 5488 file#=3 block#=614 blocks=1 obj#=0 tim=25914746917451
WAIT #139862144662288: nam='db file sequential read' ela= 108815 file#=3 block#=613 blocks=1 obj#=0 tim=25914747026421
Tuesday, April 9, 2024
One Test of Oracle Object Collection MEMBER OF Function
Following previous Blog: Performance of Oracle Object Collection Comparisons - Part1
(http://ksun-oracle.blogspot.com/2016/01/performance-of-oracle-object-collection_13.html),
we will make one test of MEMBER OF Method.
Oracle Docu writes:
The MEMBER [OF] or NOT MEMBER [OF] condition tests whether or not an element is a member of a nested table, returning the result as a Boolean value.
It seems that order method of object type is used in MEMBER OF Function to make direct one-to-one object comparisons.
Therefore, we use order method to record the number of comparisons.
Note: Tested in Oracle 19c and 22c.
At first, we fill test_tab with 1000 rows, each row has one nested table and one varray of 100 different numbers (values are 1..100).
The first element is always 1, the others (2-100) are sorted by dbms_random.value.
With positive numbers, "MEMBER OF" returns true for first element.
With negative numbers, "MEMBER OF" returns false after going all elements.
In case of varray, with positive numbers, the number of Comparisons is the same as table rows; with negative numbers, the number of Comparisons is ("table rows" * "varray size" * "number of positive numbers");
In case of nested table, with positive numbers, the number of Comparisons is more than table rows because nested table in each row is physically stored in "test_tab_obj_store" (nested table storage), and its physical sequence is not the same as its logical sequence (one can dump "test_tab_obj_store" data block to check them).
With negative numbers, the number of Comparisons is ("table rows" * "varray size" * "number of positive numbers");
Oracle Docu writes:
The MEMBER [OF] or NOT MEMBER [OF] condition tests whether or not an element is a member of a nested table, returning the result as a Boolean value.
It seems that order method of object type is used in MEMBER OF Function to make direct one-to-one object comparisons.
Therefore, we use order method to record the number of comparisons.
Note: Tested in Oracle 19c and 22c.
1. Test Setup
drop type t_obj_tab force;
drop type t_obj_varray force;
drop type t_obj force;
create or replace noneditionable package recorder as
p_cnt number := 0;
end;
/
create or replace noneditionable type t_obj as object (
p_num number,
order member function comp (c t_obj) return integer
);
/
create or replace noneditionable type body t_obj as
order member function comp (c t_obj) return integer is
begin
recorder.p_cnt := recorder.p_cnt + 1; -- count the number of calling
-- for debug
-- dbms_output.put_line('COMP Debug: p_cnt: (p_num > c.p_num) ? sign = '||recorder.p_cnt||
-- ' ('||p_num||' > '||c.p_num||' ?) = '||sign(p_num - c.p_num));
return sign(p_num - c.p_num); -- return 1, -1, 0 for bigger, less, equal
end;
end;
/
create or replace noneditionable type t_obj_tab as table of t_obj;
/
create or replace noneditionable type t_obj_varray as varray(100) of t_obj;
/
drop table test_tab;
create table test_tab (id number, obj_tab t_obj_tab, obj_varray t_obj_varray)
nested table obj_tab store as test_tab_obj_store
/
create or replace procedure fill_tab(p_rows number := 1000, p_obj_tab_size number := 100) as
l_obj_tab t_obj_tab;
l_obj_varray t_obj_varray;
begin
execute immediate'truncate table test_tab';
-- If inserting the same l_obj_tab (or same l_obj_varray), Oracle observes the same objects and optimizes (reduce) to one for the same objects.
--select cast(collect(t_obj(level)) as t_obj_tab) into l_obj_tab from dual connect by level <= l_obj_tab_size;
--select t_obj(level) bulk collect into l_obj_varray from dual connect by level <= l_obj_tab_size;
--insert into test_tab select level, l_obj_tab, l_obj_varray from dual connect by level <= l_rows;
-- Insert 1000 rows, each row has one l_obj_tab and one l_obj_varray with 100 different numbers (values are 1..100)
-- The first element is always 1, the others (2-100) are sorted by dbms_random.value.
-- For each row, insert different l_obj_tab/l_obj_varray by dbms_random.value.
dbms_random.seed(31); -- to make test stable
for i in 1..p_rows loop
with sq as (select level+1 id from dual connect by level <= (p_obj_tab_size -1) order by trunc(dbms_random.value(1, p_rows)))
select t_obj(id), t_obj(id) bulk collect into l_obj_tab, l_obj_varray
from (select 1 id from dual
union all
select * from sq);
insert into test_tab values (i, l_obj_tab, l_obj_varray);
end loop;
commit;
end;
/
-- exec fill_tab(1000, 100);
create or replace procedure memberof_test (p_size number := 100, p_sign number := 1, p_tab varchar2 := 'varray') as
l_obj_tab t_obj_tab := t_obj_tab();
l_obj_varray t_obj_varray := t_obj_varray();
l_start_time number;
l_elapsed number;
l_cnt number := 0;
begin
select cast(collect(t_obj(p_sign*level)) as t_obj_tab) into l_obj_tab from dual connect by level <= p_size order by level;
recorder.p_cnt := 0;
l_start_time := dbms_utility.get_time;
if p_tab = 'varray' then
for c in (
select * from test_tab p
where exists
(select 1 from table (p.obj_varray) t
where t_obj(t.p_num) member of cast (l_obj_tab as t_obj_tab))
) loop
l_cnt := l_cnt + 1;
end loop;
else
for c in (
select * from (select * from test_tab p order by p.id) p
where exists
(select 1 from table (p.obj_tab) t
where t_obj(t.p_num) member of cast (l_obj_tab as t_obj_tab))
-- in COMP method, "(c t_obj)" is "t_obj(t.p_num)"; (self t_obj) is from "l_obj_tab"
) loop
l_cnt := l_cnt + 1;
end loop;
end if;
l_elapsed := dbms_utility.get_time - l_start_time;
dbms_output.put_line('Selected Rows = ' || l_cnt);
dbms_output.put_line('Elapsed(centi) = ' || l_elapsed);
dbms_output.put_line('Comparisons = ' || recorder.p_cnt);
dbms_output.put_line('obj_tab.size = ' || cardinality(l_obj_tab));
end;
/
2. Test Run
At first, we fill test_tab with 1000 rows, each row has one nested table and one varray of 100 different numbers (values are 1..100).
The first element is always 1, the others (2-100) are sorted by dbms_random.value.
exec fill_tab(1000, 100);
Then we run test for varray and nested table by using "MEMBER OF" with 10 or 100 elements, once with all positive numbers, once with all negative numbers.With positive numbers, "MEMBER OF" returns true for first element.
With negative numbers, "MEMBER OF" returns false after going all elements.
exec memberof_test(10, +1, 'varray');
exec memberof_test(10, -1, 'varray');
exec memberof_test(100, +1, 'varray');
exec memberof_test(100, -1, 'varray');
exec memberof_test(10, +1, 'ntab');
exec memberof_test(10, -1, 'ntab');
exec memberof_test(100, +1, 'ntab');
exec memberof_test(100, -1, 'ntab');
3. Test Outcome
In case of varray, with positive numbers, the number of Comparisons is the same as table rows; with negative numbers, the number of Comparisons is ("table rows" * "varray size" * "number of positive numbers");
In case of nested table, with positive numbers, the number of Comparisons is more than table rows because nested table in each row is physically stored in "test_tab_obj_store" (nested table storage), and its physical sequence is not the same as its logical sequence (one can dump "test_tab_obj_store" data block to check them).
With negative numbers, the number of Comparisons is ("table rows" * "varray size" * "number of positive numbers");
SQL > exec memberof_test(10, +1, 'varray');
Selected Rows = 1000
Elapsed(centi) = 16
Comparisons = 1000
obj_tab.size = 10
SQL > exec memberof_test(10, -1, 'varray');
Selected Rows = 0
Elapsed(centi) = 325
Comparisons = 1000000
obj_tab.size = 10
SQL > exec memberof_test(100, +1, 'varray');
Selected Rows = 1000
Elapsed(centi) = 16
Comparisons = 1000
obj_tab.size = 100
SQL > exec memberof_test(100, -1, 'varray');
Selected Rows = 0
Elapsed(centi) = 3174
Comparisons = 10000000
obj_tab.size = 100
SQL > exec memberof_test(10, +1, 'ntab');
Selected Rows = 1000
Elapsed(centi) = 16
Comparisons = 4491
obj_tab.size = 10
SQL > exec memberof_test(10, -1, 'ntab');
Selected Rows = 0
Elapsed(centi) = 328
Comparisons = 1000000
obj_tab.size = 10
SQL > exec memberof_test(100, +1, 'ntab');
Selected Rows = 1000
Elapsed(centi) = 16
Comparisons = 2662
obj_tab.size = 100
SQL > exec memberof_test(100, -1, 'ntab');
Selected Rows = 0
Elapsed(centi) = 3174
Comparisons = 10000000
obj_tab.size = 100
In Memoriam of Prof. Niklaus Wirth: One Email on Program Debugging
1. Email Reply from Prof. Wirth
Sent: Tuesday, August 21, 2007 at 06:49:43 PM GMT+2
Subject: Re: Debugger Help
Dear Mr. Sun,
With your letter you raise an old argument. I doubt that I ever said
"A good programmer should not use Debugger",
but rather "A good programmer doesn't need a Debugger".
This was a bit sarcastic, and it was said in the context of teaching and solving exercises.
What I really meant was that one should strive for careful programming,
where every step is done with the certainty that it is correct,
such that at the end the whole program is correct and no search for errors (debugging) is needed.
This is quite possible and is the right way to train programmers.
However, when programs become complex, we fail to be sufficiently careful.
We make errors and must find them. Also this we must learn. But only as a "last resort".
In general, debuggers have become so sophisticated, that programmers cannot live without them.
They make debugging so common-place, that nobody even tries to design a program to
be correct from the start. This is why I exaggerated by saying to the students:
Do try to do without the help of debuggers, at least while solving my simple assignments.
In fact, I believe that the sophisticated tools, along with the very fast processors,
are largely responsible for the wide-spread replacement
of careful design by trial and error techniques. The latter is believed
to be easier and faster. And sophisticated tools are cheaper than
excellent designers. However, they cannot replace them!
To be fair, we must acknowledge another point. Very few programs are
designed from scratch and are thus in the head of an originator.
Mostly, programs grow, and programmers extend existing ones. Unfortunately, they
are often poorly documented, sometimes even wrongly documented.
Then, our work is no longer like "program design". It is rather detecting the
reasoning behind an undocumented text.Then our only resort is inspection and testing.
Then we must use every tool available to conquer the misery.
But as always, the sledgehammer must be used only when finer tools fail.
> 3. An alternative approach not to use Debugger is to insert Printout statements
> into the programs, and eventually build flags into programs to toggle and regulate
> the output finesse. How do you think of this practice?
I often do this, but remove the "debug outputs" when the problem is found.
> 4. I read again your 1984 Turning Award Lecture, and found only one place mentioning
> Debugger: "His efforts (Ken Bowles) to develop a suitable Environment with integrated
> compiler, filer, editor, and debugger caused a breakthrough:..." This sounds that
> the Debugger was appreciated.
Yes it was a big part of the success for the UCSD Pascal System.
Quick turn-around -> quick fixes.
> Also in your talk with Dr. Carlo Pescio (Published in Software Development, Vol. 5 No. 6, June 1997)
> about the 20% / 80% partition of design / debugging time, it seems that
> Debugger was not excluded from daily programming.
I never claimed that the world programs without the support of debuggers.
> In Oberon, I also heard that both a post-mortem Debugger and a runtime debugging facilities
> (BlackBox Component Builder) were implemented.
Blackbox was designed by a company in Zurich, and they were quite successful with their tools.
I hope this clarifies my points of view about programming with or without debuggers.
Sincerely yours,
Niklaus Wirth
2. Email to Prof. Wirth
Sent: Monday, July 30, 2007 at 11:24:11 AM GMT+2
Subject: Debugger Help
Dear Professor Wirth,
My name is Kun Sun, working in a software company with more than 100 developers,
of which many are ETH computer graduates. Recently we have some discussion
on the subject of "Debugger". Some of ETH graduates claim that they do not need
Debugger since Prof. Wirth taught them: "A good programmer should not use Debugger".
I have been involved in the computer field around 25 years, starting from binary programming
to nowadays-symbolic programming, always childishly seeking for the reason.
To this purpose, I would like to have your help on the following points:
1. Why a good programmer should not use Debugger? In which context does it hold?
2. A Debugger (or better called Inspector or Watcher) can reveal the runtime
behaviour of system. In the case of basic (scalar) variables, maybe the
usefulness is not tremendous, but for the composite type, like record, array,
object, XML type, it would be helpful to recognize the inherent state
and detect the side-effect of some code. On the other hand, for the program structure
like: iterative and recursive (specially non tail-recursive), Inspector can aid
in understanding of program logic. Further more, to handle with dynamic code
(program with reflection, indirection, and even string-append generated code),
a Debugger appears to be beneficial.
3. An alternative approach not to use Debugger is to insert Printout statements
into the programs, and eventually build flags into programs to toggle and regulate
the output finesse. How do you think of this practice?
4. I read again your 1984 Turning Award Lecture, and found only one place mentioning
Debugger: "His efforts (Ken Bowles) to develop a suitable Environment with integrated
compiler, filer, editor, and debugger caused a breakthrough:..." This sounds that
the Debugger was appreciated.
Also in your talk with Dr. Carlo Pescio (Published in Software Development, Vol. 5 No. 6, June 1997)
about the 20% / 80% partition of design / debugging time, it seems that
Debugger was not excluded from daily programming.
In Oberon, I also heard that both a post-mortem Debugger and a runtime debugging facilities
(BlackBox Component Builder) were implemented.
Best regards,
Kun Sun
Thursday, January 18, 2024
One Test on the Different Errors of Oracle Global Temporary Tables vs. Private Temporary Tables
This Blog shows one different behaviour of Oracle Global Temporary Table (GTT since Oracle 8i) vs. Private Temporary Table (PTT since Oracle 18c).
Note: Tested in Oracle 19.19.
We will make two GTT tests, one without "order by", one with "order by". Both throw the same ORA-01002.
We will make two PTT tests, one without "order by", one with "order by".
Without "order by", it throws ORA-08103.
With "order by", PL/SQL is successfully completed.
(see Oracle MOS:
Post Database Upgrade to 19c, Fetch from Cursor Based on Global Temporary Table Raises ORA-01002 (Doc ID 2890026.1))
Note: Tested in Oracle 19.19.
1. GTT Test
We will make two GTT tests, one without "order by", one with "order by". Both throw the same ORA-01002.
Test-1 Without Order By
drop table gtt_tab;
create global temporary table gtt_tab(x number) on commit delete rows;
-- Implicit cursor for loops array fetch 100 rows at a time by default in 10g
insert into gtt_tab(x) select level from dual connect by level <= 103;
set serveroutput on;
begin
execute immediate '
begin
for c in (select x from gtt_tab) loop
commit;
dbms_output.put_line(c.x); -- error in 101-th row
end loop;
end;';
end;
/
--The output shows ORA-01002 error:
100
begin
*
ERROR at line 1:
ORA-01002: fetch out of sequence
ORA-06512: at line 3
Test-2 With Order By
drop table gtt_tab;
create global temporary table gtt_tab(x number) on commit delete rows;
-- Implicit cursor for loops array fetch 100 rows at a time by default in 10g
insert into gtt_tab(x) select level from dual connect by level <= 103;
set serveroutput on;
begin
execute immediate '
begin
for c in (select x from gtt_tab order by x) loop
commit;
dbms_output.put_line(c.x); -- error in 101-th row
end loop;
end;';
end;
/
--The output shows the same ORA-01002 error:
100
begin
*
ERROR at line 1:
ORA-01002: fetch out of sequence
ORA-06512: at line 3
2. PTT Test
We will make two PTT tests, one without "order by", one with "order by".
Without "order by", it throws ORA-08103.
With "order by", PL/SQL is successfully completed.
Test-1 Without Order By
drop table ora$ptt_tab;
create private temporary table ora$ptt_tab (x number) on commit drop definition;
-- Implicit cursor for loops array fetch 100 rows at a time by default in 10g
insert into ora$ptt_tab(x) select level from dual connect by level <= 103;
set serveroutput on;
begin
execute immediate '
begin
for c in (select x from ora$ptt_tab) loop
commit;
dbms_output.put_line(c.x); -- error in 101-th row
end loop;
end;';
end;
/
--The output shows ORA-08103 error:
100
begin
*
ERROR at line 1:
ORA-08103: object no longer exists
ORA-06512: at line 3
Test-2 With Order By
drop table ora$ptt_tab;
create private temporary table ora$ptt_tab (x number) on commit drop definition;
-- Implicit cursor for loops array fetch 100 rows at a time by default in 10g
insert into ora$ptt_tab(x) select level from dual connect by level <= 103;
set serveroutput on;
begin
execute immediate '
begin
for c in (select x from ora$ptt_tab order by x) loop
commit;
dbms_output.put_line(c.x);
end loop;
end;';
end;
/
--The output shows successfully completed:
103
PL/SQL procedure successfully completed.
The behaviour can be varied following different Oracle releases.(see Oracle MOS:
Post Database Upgrade to 19c, Fetch from Cursor Based on Global Temporary Table Raises ORA-01002 (Doc ID 2890026.1))
Wednesday, October 25, 2023
ORA-28268: Exceeded the maximum allowed size for Context information in a session
Note: Tested in Oracle 19.18.
Oracle document:
It is only applied to local context (dba_context.type = 'ACCESSED LOCALLY')
(for global context, ORA-04031 when too many global context entries, check v$sgastat.name = 'Global Context').
It's value can be modified by:
The name "_session_context_size" seems misleading, mabybe renamed as "_session_context_entry_limit".
1. Test Setup
-- code from Blog: "library cache: mutex X" and Application Context
-- (http://ksun-oracle.blogspot.com/2016/11/library-cache-mutex-x-and-application.html)
create or replace context test_ctx using test_ctx_pkg;
--create or replace context test_ctx using test_ctx_pkg accessed globally;
create or replace package test_ctx_pkg is
procedure set_val (attr varchar2, val varchar2);
end;
/
create or replace package body test_ctx_pkg is
procedure set_val (attr varchar2, val varchar2) as
begin
--dbms_session.clear_all_context('TEST_CTX');
dbms_session.set_context('TEST_CTX', attr, val);
end;
end;
/
create or replace procedure ctx_set(p_cnt number, attr_pre varchar2, val_pre varchar2) as
begin
for i in 1..p_cnt loop
test_ctx_pkg.set_val(attr_pre||i, val_pre||i); -- 'library cache: mutex X' on TEST_CTX
end loop;
end;
/
create or replace procedure test_ORA_28268 (p_cnt number) as
l_attr_pre varchar2(32000);
l_val_pre varchar2(32000);
l_val varchar2(32000);
begin
--dbms_session.clear_all_context('TEST_CTX');
ctx_set(p_cnt, 'ATTR_', 'VAL_');
select sys_context('TEST_CTX', 'ATTR_'||1) into l_val from dual;
dbms_output.put_line('l_attr='||'ATTR_'||1||', VAL='||l_val);
select sys_context('TEST_CTX', 'ATTR_'||p_cnt) into l_val from dual;
dbms_output.put_line('l_attr='||'ATTR_'||p_cnt||', VAL='||l_val);
end;
/
create or replace procedure list_context as
l_tab dbms_session.appctxtabtyp;
l_size number;
begin
dbms_session.list_context(l_tab, l_size);
dbms_output.put_line('l_tab.count: '||l_tab.count||', l_size:'||l_size);
for i in 1..l_tab.count loop
dbms_output.put_line('namespace: '||l_tab(i).namespace||', attribute: '||l_tab(i).attribute||', value: '||l_tab(i).value);
end loop;
end;
/
2. Test Run
SQL > exec test_ORA_28268(10000-300);
l_attr=ATTR_1, VAL=VAL_1
l_attr=ATTR_9700, VAL=VAL_9700
SQL > exec test_ORA_28268(10000+300);
BEGIN test_ORA_28268(10000+300); END;
ERROR at line 1:
ORA-28268: Exceeded the maximum allowed size for Context information in a session
ORA-06512: at "SYS.DBMS_SESSION", line 141
ORA-06512: at "K.TEST_CTX_PKG", line 5
ORA-06512: at "K.CTX_SET", line 4
ORA-06512: at "K.TEST_ORA_28268", line 7
ORA-06512: at line 1
3. ORA-28268
Oracle document:
28268, 0000, "Exceeded the maximum allowed size for Context information in a session"
// *Cause: The maximum size specified by the _session_context_size
// init.ora parameter was exceeded.
// *Action: Please change the value for _session_context_size in the
//
ORA-28268 is raised when the number of session local context entries exceeded limit (session local context array)
which is defined by "_session_context_size" (default 10,000).It is only applied to local context (dba_context.type = 'ACCESSED LOCALLY')
(for global context, ORA-04031 when too many global context entries, check v$sgastat.name = 'Global Context').
It's value can be modified by:
alter system set "_session_context_size"=10000 scope=spfile;
One cause of ORA-28268 is probably session local context leak.The name "_session_context_size" seems misleading, mabybe renamed as "_session_context_entry_limit".
Wednesday, September 20, 2023
Oracle Index Root Modification CBC Latch Contention: Workaround Studies
In Oracle applications, often there are certain central tables,
which are accessed concurrently by many sessions using indexes.
If one index root block is modified due to branch or leaf block split when running DML statements,
the system could experience hard to predict heavy CBC Latch Contention on root block.
In this Blog, we would try to set apart root block modification from DML operations so that root block modification is performed at first, and then subsequent DML are executed.
The purpose is only for illustrative, experimental and feasibility studies in the hope that Oracle can refine the idea.
Test code is based on Blogs:
Index Service ITL and Recursive Transaction
Cache Buffer Chains Latch Contention Case Study-2: Reverse Primary Key Index
Oracle 19.18 Wait Event 'latch: cache buffers chains' P3: block number
Note: Tested in Oracle 19.18.
In this Blog, we would try to set apart root block modification from DML operations so that root block modification is performed at first, and then subsequent DML are executed.
The purpose is only for illustrative, experimental and feasibility studies in the hope that Oracle can refine the idea.
Test code is based on Blogs:
Index Service ITL and Recursive Transaction
Cache Buffer Chains Latch Contention Case Study-2: Reverse Primary Key Index
Oracle 19.18 Wait Event 'latch: cache buffers chains' P3: block number
Note: Tested in Oracle 19.18.
1. Test Setup
--=================== Test Setup in session-1 ===================--
drop table test_tab purge;
create table test_tab (id number, val number);
drop index test_tab#r;
create unique index test_tab#r on test_tab(id) reverse;
alter table test_tab add constraint test_tab#r primary key (id);
truncate table test_tab;
insert into test_tab select level, -level from dual connect by level <= 4905;
commit;
-- Test Code to insert one row to trigger leaf block split, and root block modification
create or replace procedure root_modi_cbc_latch_workaround (p_insert_id number, p_allow_seconds number := 5) as
type t_name_tab is table of dba_segments.segment_name%type;
type t_file_tab is table of dba_segments.header_file%type;
type t_block_tab is table of dba_segments.header_block%type;
l_name_tab t_name_tab := t_name_tab();
l_file_tab t_file_tab := t_file_tab();
l_block_tab t_block_tab := t_block_tab();
l_cnt number := 0;
l_scn number;
l_scn_ts timestamp;
l_modi_ts timestamp;
l_msg_str varchar2(200);
l_modi boolean := false;
begin
-- collect indexes and their root files/root blocks
-- @TODO store those in a package variable to workaround dba_segments performance
with sq as (select /*+ materialize */ index_name from dba_indexes where table_name = 'TEST_TAB')
select /*+ leading(q) use_nl(s) */ q.index_name, header_file, header_block + 1
bulk collect into l_name_tab, l_file_tab, l_block_tab
from sq q, dba_segments s where s.segment_name = q.index_name;
dbms_session.sleep(p_allow_seconds); -- simulate appliaction
-- check if there are any root block modifications. If yes, rollback, re-insert. If not, exit loop.
for i in 1 ..2 loop
dbms_output.put_line(systimestamp||'--- Run ' ||i||'--- set savepoint');
savepoint sp;
insert into test_tab values(p_insert_id, -p_insert_id);
l_modi_ts := cast (systimestamp as timestamp);
if i = 1 then
for k in 1..l_name_tab.count loop
select count(1) into l_cnt from v$bh
where file#=l_file_tab(k) and block# = l_block_tab(k) and status = 'xcur'; --and dirty = 'Y'
select max(hscn_wrp*power(2, 32) + hscn_bas) into l_scn from x$bh
where l_cnt > 0 and state = 1 and hscn_wrp > 0 and file#=l_file_tab(k) and dbablk=l_block_tab(k); --state=1, 'xcur'
if l_scn > 0 then
l_scn_ts := scn_to_timestamp(l_scn); -- scn_to_timestamp session cached. run test in one new session.
end if;
l_msg_str := systimestamp||'--- Run ' ||i||'--- Index '||l_name_tab(k)||' Root (File = '||l_file_tab(k)||', Block = '||l_block_tab(k)||'), '||
'l_cnt = '||l_cnt||', l_scn = '||l_scn||', l_scn_ts = '||l_scn_ts;
dbms_output.put_line(l_msg_str);
-- scn_to_timestamp: the usual precision of the result value is 3 seconds.
if l_scn_ts between l_modi_ts - numtodsinterval(p_allow_seconds, 'SECOND') and l_modi_ts then
dbms_output.put_line('*** Root modified at '||l_modi_ts||', Root Index Modi at '||l_scn_ts ||
', rollback to make only root modi trx performed, then re-insert.');
l_modi := true;
rollback to savepoint sp; -- only rollback main trx, root modi recursive trx committed (un-rollbackable)
exit; -- one index root modi found, finish modi recursive trx, exit internal loop
end if;
end loop;
if not l_modi then
dbms_output.put_line('*** Root not modified');
exit;
end if;
end if;
end loop;
end;
/
2. Test Run
--========== Test Run in session-2 (to repeat test, run "Test Setup" at first) ==========--
set serveroutput on
alter session set nls_timestamp_format ='YYYY*MON*DD HH24:MI:SS.FF9';
select scn_to_timestamp(ora_rowscn), t.* from test_tab t where id >= 4904 order by id;
exec root_modi_cbc_latch_workaround(4906);
exec root_modi_cbc_latch_workaround(4907);
select scn_to_timestamp(ora_rowscn), t.* from test_tab t where id >= 4904 order by id;
rollback;
3. Test Output
--=================== Test Output in session-2 ===================--
12:01:34 SQL > select scn_to_timestamp(ora_rowscn), t.* from test_tab t where id >= 4904 order by id;
SCN_TO_TIMESTAMP(ORA_ROWSCN) ID VAL
-------------------------------- ---------- ----------
2023*SEP*20 12:01:17.000000000 4904 -4904
2023*SEP*20 12:01:17.000000000 4905 -4905
2 rows selected.
12:01:34 SQL > exec root_modi_cbc_latch_workaround(4906);
20-SEP-2023 12:01:42 +02:00--- Run 1--- set savepoint
20-SEP-2023 12:01:42 +02:00--- Run 1--- Index TEST_TAB#R Root (File = 22, Block = 35467), l_cnt = 1,
l_scn = 12776808521751, l_scn_ts = 2023*SEP*20 12:01:41.000000000
*** Root modified at 2023*SEP*20 12:01:42.271069000, Root Index Modi at 2023*SEP*20 12:01:41.000000000,
rollback to make only root modi trx performed, then re-insert.
20-SEP-2023 12:01:42 +02:00--- Run 2--- set savepoint
Elapsed: 00:00:07.80
12:01:42 SQL > exec root_modi_cbc_latch_workaround(4907);
20-SEP-2023 12:01:50 +02:00--- Run 1--- set savepoint
20-SEP-2023 12:01:50 +02:00--- Run 1--- Index TEST_TAB#R Root (File = 22, Block = 35467), l_cnt = 1,
l_scn = 12776808521752, l_scn_ts = 2023*SEP*20 12:01:41.000000000
*** Root not modified
Elapsed: 00:00:07.86
12:01:50 SQL > select scn_to_timestamp(ora_rowscn), t.* from test_tab t where id >= 4904 order by id;
SCN_TO_TIMESTAMP(ORA_ROWSCN) ID VAL
-------------------------------- ---------- ----------
2023*SEP*20 12:01:17.000000000 4904 -4904
2023*SEP*20 12:01:17.000000000 4905 -4905
2023*SEP*20 12:01:17.000000000 4906 -4906
2023*SEP*20 12:01:17.000000000 4907 -4907
4 rows selected.
12:01:50 SQL > rollback;
Rollback complete.
Test output shows that both new rows with ID 4906 and 4907 are inserted, only ID 4096 triggers root block modification,
but ID 4097 does not.
Subscribe to:
Posts (Atom)