Tracing Logical IOs Extended SQL trace is an excellent tool for troubleshooting and optimizing Oracle systems. However, if an event is not instrumented to emit information, it will not be found in the output. Logical i/o (LIO) operations are one class of these uninstrumented events. Oracle does provide several debugging events that enable tracing of several types of LIO. Unfortunately, these events are not documented in the same way that the 10046 event. In fact, a search of metalink and the internet revealed few references to these events and no documentation. To understand these events, we approached our research from a traditional experiment, observe and deduce method.
What we cover in this paper This paper is about the mechanics of tracing LIO, focusing on the actual output from the trace events and what we currently can observe. This is not a definitive guide on tracing LIO, it is an introduction to the tools available to monitor them. In our research, we have found that every answer seems to generate more questions. The companion presentation (available online) will review the mechanics, but its focus is more on what we learned in the process and what we still have yet to learn.
Why trace logical i/os? Extended sql trace will offer insight into many aspects of how Oracle operates, but it does not include some areas, LIO being one area. When a FETCH line is written, the number of consistent reads (cr) is included. Unfortunately, that is the extent of the information. What blocks were read in consistent read mode? Is there a correlation between the crs written in a sql trace file and the blocks read or are they correlated to rows?
Supporting scripts To decode and decipher some of the output, we created several functions and a table. The source code for these objects can be found at the end of this paper and on the website. This code is provided without any warranty.
Caveats We hate to start off a paper with “here’s what we don’t know”, but in the interest of maintaining the integrity of our research process, we feel that it is important to keep a few facts in mind. •
The events that we have used to trace LIOs are not documented, not in Metalink, not on the net. Everything that we have learned is a result of what we have known about Oracle and deductions made from our experiments.
•
As we are using undocumented commands and events, do not use them on any important database. We have not tested the events on all releases, all platforms, all configurations, so the impact on availability and performance is not known.
•
What you read here are observations, not known facts. We will cover the deductions and additional questions in the presentation.
•
Your responsibility to not accept what we say, but think about it, test it, criticize it (constructively, please). If we are wrong, if you have a different perspective, please tell us.
Fink & Deshpande
Page 1
Tracing Logical IOs •
Finally, and perhaps most importantly, this paper, the presentation, test scripts and output will be published to http://www.optimaldba.com. Download them, review them, repeat them, and break them. This is not the end of the exploration into logical i/os. With your help, it is the beginning.
Events In the oraus.msg file, there are four debugging events that are related to consistent reads and the application of undo that we tested. 10200 10201 10202 10226
"consistent read buffer status" "consistent read undo application" "consistent read block header" "trace CR applications of undo for data operations"
There are other events in the messages file, but we did not find useful information written to trace files for these other events.
Enabling tracing and options Like 10046, there are many ways to set the events. As with 10046, do not activate these events at the instance level. As these events are not documented nor used in the normal course of operations, they may not be supported. You should not use them on a database that is not ‘disposable’. In the course of our testing, we did not find any problems related to performance or availability.
Alter session To set it in your session using the ALTER SESSION syntax. alter session set events ‘10200 trace name context forever’;
To turn it off, use the following. alter session set events ‘10200 trace name context off’;
dbms_system.set_ev To set it in a session using the dbms_system.set_ev syntax. exec dbms_system.set_ev(9,28,10200,1,'');
To turn it off in the session using the dbms_system.set_ev syntax. exec dbms_system.set_ev(9,28,10200,0,'');
Fink & Deshpande
Page 2
Tracing Logical IOs Testing Our main focus of testing was to start the discovery process. The scope of our testing was limited so that we could begin gaining knowledge and was not meant to examine every setting, every platform, every release, etc. We also enabled 10046 level 8 tracing to see additional information.
Phase 1 The first issue to be addressed was the levels, if any, which were available for the 10200 tracing. We tested levels 1,2,4,8,12 and 16, but all of the output was identical. We also tested on 2 different platforms (Windows and HP-UX) and releases (9ir2, 10g). Again the output was identical for each level, though we did find minor cross-platform differences Our observation from these tests was that there were not different levels in the trace output for the 10200 event. From this point on, we tested with events on or off and did not test for different levels for each event.
Phase 2 Once we observed that there did not appear to be additional levels, we repeated the tests for different events. In a single session, once an event was set, we left it set when we added a new event. The resulting output was cumulative and we could see what new lines were added and where they were written in the output. This was important as we found that the 10200 event was a summary event and all the other events were written between the start and finish lines of this event. The basic steps were performed in three sessions. t – Time s - Session t00 s0 – create test tables using create table as select from source table (this leaves less transaction information in the test table), build index on 2nd table t01 s1 – set appropriate events, environment in query session t02 s1 – query test table using table access path t03 s2 – update test table, but do not commit t04 s0 – query v$transaction for scn, transaction id (xid), undo block address (uba) values t05 s1 – query test table using table access path t06 s2 – commit updates t07 s0 – query v$transaction for scn, transaction id (xid), undo block address (uba) values t08 s1 – query test table using table access path to see updated values # Perform tests using another access path t11 s1 – query test table using index access path t12 s2 – update test table, but do not commit t13 s0 – query v$transaction for scn, transaction id (xid), undo block address (uba) values t14 s1 – query test table using index access path t15 s2 – commit updates t16 s0 – query v$transaction for scn, transaction id (xid), undo block address (uba) values t17 s1 – query test table using index access path to see updated values
Fink & Deshpande
Page 3
Tracing Logical IOs These test steps were repeated for all events (10200, 10201, 10202, 10226). As a new event was tested, the currently active events were left on. This output provided the first set of meaningful data and presented us with significant questions. Many of these questions are centered on the 10200 and 10201 events. We were also able to make deductions about how the consistent read process was implemented.
Phase 3 We began to test to answer specific questions and construct tests accordingly. These tests included multiple updates to the same block, applying undo from multiple transactions, and updating index entries. As will happen, these tests might answer some questions, but would often raise new ones.
Trace Output Common Fields Many of the individual components of the fields can be seen for transactions (query, update, delete) by querying v$transaction. However, the trace file writes the numbers in hexadecimal notation and some translation is required. You can use the hex2dec, hex2scnbw, hex2segment functions (Appendix B) to translate the hexadecimal notation to decimal notation.
unknown In the documentation for each event, certain fields are labeled as unknown. This means that the values changed during the course of testing, but the nature of the fields could not be discerned.
xid – Transaction Identifier Composed of 3 hexadecimal numbers. This is how Oracle identifies the undo transaction table slot. The first number is the undo segment number (v$transaction.xidusn) The second number is the undo transaction table slot (v$transaction.xidslt) The third number is the transaction table sequence number (v$transaction.xidsqn)
uba – Undo Block Address Composed of 3 hexadecimal numbers. This is the current physical address of undo to be applied of the physical address of the next piece of undo in the undo chain. The first number is the block. The leading 0x008 should not be used to determine the block. (v$transaction.ubablk) The second number is the sequence (v$transaction.ubasqn) The third number is the record (v$transaction.ubarec)
scn – System Change Number or System Commit Number Composed of 2 hexadecimal numbers The first number is the scn wrap The second number is the scn base
Fink & Deshpande
Page 4
Tracing Logical IOs block <n> : <hex> - Physical address of data/index block The first number is not the block, but the tablespace number. This is not a hexadecimal number. The second number is the hexadecimal address of the data or index block.
10200 Event "consistent read buffer status" This event provides a summary of consistent read operations. 10200 output consists of several lines per block read. The event output is always bounded by a started and a finished line. The superscript numbers are not part of the output. Consistent read started for block 71 : 01c000922 env: (scn: 0x0779.b26ae3bf3 xid: 0x0000.000.000000004 uba: 0x00000000.0000.005 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) CR exa ret 96 on: 020AC3287 scn: 0xffff.ffffffff8 xid: 0x0000.000.000000009 uba: 0x00000000.0000.0010 scn: 0xffff.ffffffff11 sfl: 0 CR exa ret 16 on: 7AC7EA787 scn: 0x0779.b26ae3b68 xid: 0x0000.000.000000009 uba: 0x00000000.0000.0010 scn: 0x0779.b26ae3b611 sfl: 0 Consistent read finished for block 71 : 01c000922 Consistent read finished for block 71 : 01c000922
10200 Trace Output Fields Fields that did not change are not identified. 1 – tablespace id 2 – datablock address 3 – consistent read scn. 4 – transaction id 5 – undo block address 6 – unknown 7 – unknown 8 – scn of the transaction being undone 9 – transaction id of the transaction being undone. 10 – undo block address of the transaction being undone. 11 – block’s consistent read scn
EVENT 10201 “consistent read undo application” 10201 traces the row level application of undo. For each row, index entry or itl slot, this block is written. If no undo is applied, the block is not written. Applying CR undo to block 71 : 1c000922 itl entry 023: xid: 0x0002.008.00003a524 uba: 0x00800026.0853.085 flg: ----6 lkc: 2177 fsc: 0x01f8.000000008 CRS upd rd env9: (scn: 0x0779.b26ae3bf10 xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) undo env11: (scn: 0x0779.b26ae3bf12 xid: 0x0002.008.00003a524 uba: 0x00800026.0853.085 statement num=0 parent xid: xid: 0x0000.000.0000042c13 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000)
Fink & Deshpande
Page 5
Tracing Logical IOs CRS upd (before): 7AC7E3B814 scn: 0x0779.b26ae3bf10 xid: 0x0000.000.0000000015 uba: 0x00000000.0000.0016 scn: 0x0779.b26ae3bf17 sfl: 018 CRS upd (after) : 7AC7E3B814 scn: 0x0779.b26ae3bf10 xid: 0x0002.008.00003a524 uba: 0x00800026.0853.085 scn: 0x0779.b26ae3bf17 sfl: 018
10201 Trace Output Fields 1
– tablespace id – datablock address 3 – The Interested Transaction Entry (ITE), or slot in the Interested Transaction List (ITL) 4 – transaction id of the insert/update/delete 5 – undo block address of the insert/update/delete 6 – Flag indicating state of the entry 7 – The number of rows in the block locked by the transaction that is using the ITE 8 – The free space credit (fsc) or system commit number (scn) 9 – consistent read environment 10 – query scn 11 – undo environment 12 – scn of the transaction being ‘undone’ 13 – unknown 14 – unknown 15 – transaction id of previously applied undo 16 – undo block address of previously applied undo 17 – block scn 18 – unknown 2
10202 Event "consistent read block header" This event writes the datablock header as it exists for the read consistent version of the block. This is written even if undo is not applied to the block. Consistent read complete... Block header dump: 0x01c000821 Object id on Block? Y seg/obj: 0x199a2 csc: 0x779.b26be6bb3 fsl: 0 fnx: 0x0 ver: 0x01 Itl4 0x01 0x02 0x03
Xid5 0xffff.000.00000000 0x0000.000.00000000 0x0000.000.00000000
itc: 3
Uba6 0x00000000.0000.00 0x00000000.0000.00 0x00000000.0000.00
flg: -
typ: 1 - DATA
Flag7 Lck8 Scn/Fsc9 C--0 scn 0x0779.b26be6bb ---0 fsc 0x0000.00000000 ---0 fsc 0x0000.00000000
10202 Trace Output Fields 1
– datablock address – object id 3 – scn of last block cleanout 4 – itl index number 5 – transaction id 6 – undo block address 7 – flag 2
Fink & Deshpande
Page 6
Tracing Logical IOs 8 9
– number of rows in block affected by transaction – scn or free space credit
10226 "trace CR applications of undo for data operations" This event shows the actual undo applied to the block. applied to 0x1e2340141: KTB Redo op: 0x02 ver: 0x01 op: C uba: 0x008008a2.08e0.0f2 KDO Op code: URP row dependencies Disabled xtype: CR3 bdba: 0x01c000ca4 hdba: 0x01c000c95 itli: 26 ispac: 0 maxfr: 4863 tabn: 0 slot: 21(0x15)7 flag: 0x2c lock: 0 ckix: 0 ncol: 58 nnew: 2 size: 0 col 19: [300] 52 65 63 6f 72 64 20 32 3210 … col 29: [ 7] 78 69 01 19 16 2f 1a10
10226 Trace Output Fields 1
– unknown – address of undo being applied 3 – consistent read operation 4 – datablock address 5 – segment header block address 6 – ITE 7 – slot or row number in the block 8 – number of columns in table 9 – column number (starts at 0) 10 – column data prior to change 2
Fink & Deshpande
Page 7
Tracing Logical IOs Appendix A: All Events Combined Consistent read started for block 7 : 01c000ec env: (scn: 0x0779.b26be7bd xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) CR exa ret 9 on: 020AC328 scn: 0xffff.ffffffff xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0xffff.ffffffff sfl: 0 CR exa ret 1 on: 7AC74338 scn: 0x0779.b26be7bb xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0x0779.b26be7bb sfl: 0 Applying CR undo to block 7 : 1c000ec itl entry 02: xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0c flg: ---lkc: 7 fsc: 0x0000.00000000 CRS upd rd env: (scn: 0x0779.b26be7bd xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) undo env: (scn: 0x0779.b26be7bf xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0c statement num=0 parent xid: xid: 0x0000.000.0000042c scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) CRS upd (before): 7AC73A38 scn: 0x0779.b26be7bd xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 scn: 0x0779.b26be7bf sfl: 0 CRS upd (after) : 7AC73A38 scn: 0x0779.b26be7bd xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0c scn: 0x0779.b26be7bf sfl: 0 applied to 0x1e1d4014: KTB Redo op: 0x02 ver: 0x01 op: C uba: 0x008000b8.08c0.0b KDO Op code: URP row dependencies Disabled xtype: CR bdba: 0x01c000ec hdba: 0x01c000e9 itli: 2 ispac: 0 maxfr: 4863 tabn: 0 slot: 5(0x5) flag: 0x2c lock: 0 ckix: 0 ncol: 5 nnew: 2 size: 0 col 1: [300] 52 65 63 6f 72 64 20 35 30 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 col 2: [ 7] 78 69 01 19 16 2f 1a Applying CR undo to block 7 : 1c000ec itl entry 02: xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0b flg: ---lkc: 6 fsc: 0x0000.00000000 CRS upd rd env: (scn: 0x0779.b26be7bd xid: 0x0000.000.00000000 uba: 0x00000000.0000.00 statement num=0 parent xid: xid: 0x0000.000.00000000 scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) undo env: (scn: 0x0779.b26be7bf xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0b statement num=0 parent xid: xid: 0x0000.000.0000042c scn: 0x0000.00000000 0sch: scn: 0x0000.00000000) CRS upd (before): 7AC73A38 scn: 0x0779.b26be7bd xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0c scn: 0x0779.b26be7bf sfl: 0 CRS upd (after) : 7AC73A38 scn: 0x0779.b26be7bd xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0b scn: 0x0779.b26be7bf sfl: 0 applied to 0x1e1d4014: KTB Redo op: 0x02 ver: 0x01 op: C uba: 0x008000b8.08c0.0a KDO Op code: URP row dependencies Disabled xtype: CR bdba: 0x01c000ec hdba: 0x01c000e9 itli: 2 ispac: 0 maxfr: 4863 tabn: 0 slot: 4(0x4) flag: 0x2c lock: 0 ckix: 0 ncol: 5 nnew: 2 size: 0
Fink & Deshpande
Page 8
Tracing Logical IOs col 1: [300] 52 65 63 6f 72 64 20 34 39 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 20 col 2: [ 7] 78 69 01 19 16 2f 1a Applying CR undo to block 7 : 1c000ec itl entry 02: xid: 0x0009.02d.00003a5c uba: 0x008000b8.08c0.0a flg: ---lkc: 5 fsc: 0x0000.00000000 Consistent read complete... Block header dump: 0x01c000ec Object id on Block? Y seg/obj: 0x19a7 csc: 0x779.b26be7bf itc: 3 flg: - typ: 1 - DATA fsl: 0 fnx: 0x0 ver: 0x01 Itl Xid 0x01 0xffff.000.00000000 0x0779.b26be7a8 0x02 0x0000.000.00000000 0x0000.00000000 0x03 0x0000.000.00000000 0x0000.00000000
Uba 0x00000000.0000.00
Flag C---
Lck 0
scn
0x00000000.0000.00
----
0
fsc
0x00000000.0000.00
----
0
fsc
Scn/Fsc
Consistent read finished for block 7 : 1c000ec Consistent read finished for block 7 : 1c000ec
Fink & Deshpande
Page 9
Tracing Logical IOs Appendix B: Scripts Extent Map Create an extent mapping table to speed the query to determine the owner of the block being read. The hex2segment function reads this table. Since it is a temporary table, it will need to be reloaded for each session. create global temporary table ext_map (tablespace_name varchar2(30), tablespace_id number, owner varchar2(30), segment_name varchar2(30), segment_type varchar2(30), file_id number, relative_fno number, begin_block number, end_block number, extent_id number) on commit preserve rows / create index em_file_blocks on ext_map (file_id, begin_block, end_block) / insert into ext_map (select t.name, t.ts#, x.owner, x.segment_name, x.segment_type, x.file_id, x.relative_fno, x.block_id, (x.block_id + x.blocks - 1), extent_id from dba_extents x, sys.ts$ t where t.name = x.tablespace_name) / commit /
Fink & Deshpande
Page 10
Tracing Logical IOs hex2dec function This function translates a hexadecimal notation to decimal value. This is required for the other hex2* functions. CREATE OR REPLACE FUNCTION hex2dec (hex_num_in IN vARCHAR2) RETURN NUMBER IS invalid_hex EXCEPTION; hex_num varchar2(100) := NULL; hex_num_len number := 0; hex_pos number := 0; hex_value char(1) := NULL; dec_value number := 0; dec_result number := 0; BEGIN hex_num := upper(ltrim(hex_num_in,'0')); hex_num_len := length(hex_num); FOR hex_pos IN REVERSE 1..hex_num_len LOOP hex_value := substr(hex_num, hex_pos, 1); dec_value := instr('0123456789ABCDEF', hex_value); IF dec_value = 0 THEN raise_application_error(-20001, 'Invalid Hexadecimal Number'); ELSE dec_value := dec_value - 1; END IF; dec_result := dec_result + (dec_value * power(16,(length(hex_num) - hex_pos))); END LOOP; RETURN dec_result; END; /
hex2segment function This function translates a hexadecimal notation for the datablock address to the format of owner.segment_name (segment_type). CREATE OR REPLACE FUNCTION hex2segment (hex_dbaddr_in VARCHAR2) RETURN VARCHAR2 IS dec_result number := 0; file# number := 0; block# number := 0; owner VARCHAR2(30); segment VARCHAR2(30); seg_type VARCHAR2(30); BEGIN dec_result := hex2dec(hex_dbaddr_in); file# := dbms_utility.data_block_address_file(dec_result);
Fink & Deshpande
Page 11
Tracing Logical IOs block# := dbms_utility.data_block_address_block(dec_result); select owner, segment_name, segment_type into owner, segment, seg_type from ext_map where file_id = file# and begin_block <= block# and end_block >= block#; return owner||'.'||segment||'('||seg_type||')'; END; /
hex2scn function This function translates a wrap.base hexadecimal notation for the scn format to a single decimal value. CREATE OR REPLACE FUNCTION hex2scn (hex_scn_in VARCHAR2) RETURN NUMBER IS scn_out NUMBER := 0; BEGIN scn_out := (hex2dec(substr((substr(hex_scn_in,1,(instr(hex_scn_in,'.'))-1)),3)) * 4294967295 ) + hex2dec((substr(hex_scn_in,(instr(hex_scn_in,'.')+1)))); RETURN scn_out; END; /
hex2scnwb function This function translates a wrap.base hexadecimal notation for the scn format to a wrap.base decimal value. CREATE OR REPLACE FUNCTION hex2scnwb (hex_scn_in VARCHAR2) RETURN VARCHAR2 IS scn_out VARCHAR2(20) := NULL; BEGIN scn_out := hex2dec(substr((substr(hex_scn_in,1, (instr(hex_scn_in,'.')) -1)),3))||'.'|| hex2dec((substr(hex_scn_in,(instr(hex_scn_in,'.')+1)))); RETURN scn_out; END; /
Querying information from v$transaction column xid format a30 col uba format a30 col scn format a20
Fink & Deshpande
Page 12
Tracing Logical IOs select xidusn||'.'||xidslot||'.'||xidsqn as xid, start_ubablk||'.'||start_ubasqn||'.'||start_ubarec as uba, start_scnw||'.'||start_scnb as scn from v$transaction;
Querying 10200/10201 trace files as external tables CREATE DIRECTORY trace_dir AS 'c:\oracle\admin\tpr9204\udump\' / create table trace_10200_raw (txt varchar2(4000)) ORGANIZATION EXTERNAL (type oracle_loader default directory trace_dir access parameters (records delimited by newline fields missing field values are null (txt position(1:4000) ) ) location ('LIO_test.trc')) / DECLARE CURSOR c_10200_trc IS SELECT txt FROM trace_10200_raw; r_10200_trc c_10200_trc%ROWTYPE; line_num trc_txt cr_block_hex cr_block_name cr_return_val cr_on_val cr_scn_val cr_uba_val cr_xid_val cr_scn_hex trc_sql_statement
NUMBER VARCHAR2(4000) VARCHAR2(20) VARCHAR2(1024) NUMBER VARCHAR2(8) VARCHAR2(20) VARCHAR2(40) VARCHAR2(40) VARCHAR2(1024) BOOLEAN
:= := := := := := := := := := :=
0; NULL; NULL; NULL; 0; NULL; NULL; NULL; NULL; NULL; FALSE;
BEGIN dbms_output.enable(1000000); FOR r_10200_trc in c_10200_trc LOOP line_num := line_num + 1; trc_txt := r_10200_trc.txt; IF trc_txt LIKE 'Consistent read started%' THEN cr_block_hex := SUBSTR(trc_txt, INSTR(trc_txt, ':')+2); dbms_output.put_line('****'); dbms_output.put_line(to_char(line_num, '00000009')||' CR Start '||TRIM(cr_block_hex)||' '||hex2segment(cr_block_hex)); ELSIF trc_txt LIKE'Consistent read finished%' THEN cr_block_hex := SUBSTR(trc_txt, INSTR(trc_txt, ':')+2);
Fink & Deshpande
Page 13
Tracing Logical IOs dbms_output.put_line(to_char(line_num, '00000009')||' CR Finish '||hex2segment(cr_block_hex)); ELSIF trc_txt LIKE 'CRS upd (after)%' THEN cr_on_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, ': ')+2,(INSTR(trc_txt, ' scn:') - (INSTR(trc_txt, ': ')+2)))); cr_scn_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, 'scn: ')+5,(INSTR(trc_txt, ' xid:') - (INSTR(trc_txt, 'scn: ')+5)))); cr_xid_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, 'xid: ')+5,(INSTR(trc_txt, ' uba:') - (INSTR(trc_txt, 'xid: ')+5)))); cr_uba_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, 'uba: ')+5,(INSTR(trc_txt, ' scn:',1,2) - (INSTR(trc_txt, 'uba: ')+5)))); dbms_output.put_line(to_char(line_num, '00000009')||' CR Applied '||to_char(cr_return_val)||'/'||cr_on_val||' SCN '||TRIM(cr_scn_val)||'/'||hex2scnbw(cr_scn_val)||' XID '||TRIM(cr_xid_val)||' UBA '||TRIM(cr_uba_val)); ELSIF trc_txt LIKE 'CR exa ret%' THEN cr_return_val := SUBSTR(trc_txt, INSTR(trc_txt, 'ret ')+4,(INSTR(trc_txt, ' on:') - (INSTR(trc_txt, 'ret ')+4))); cr_on_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, 'on: ')+4,(INSTR(trc_txt, ' scn:') - (INSTR(trc_txt, 'on: ')+4)))); cr_scn_val := TRIM(SUBSTR(trc_txt, INSTR(trc_txt, 'scn: ')+5,(INSTR(trc_txt, ' xid:') - (INSTR(trc_txt, 'scn: ')+5)))); dbms_output.put_line(to_char(line_num, '00000009')||' CR Return Value '||to_char(cr_return_val)||'/'||cr_on_val||' SCN '||TRIM(cr_scn_val)||'/'||hex2scnbw(cr_scn_val)); ELSIF trc_txt LIKE 'FETCH%' THEN dbms_output.put_line(to_char(line_num, '00000009')||' '||trc_txt); ELSIF trc_txt LIKE '%db file%' THEN dbms_output.put_line(to_char(line_num, '00000009')||' '||trc_txt); ELSIF trc_txt LIKE ' env: (scn%' THEN cr_scn_hex := TRIM(SUBSTR(trc_txt, (INSTR(trc_txt, 'scn:')+5), (INSTR(trc_txt, 'xid') - (INSTR(trc_txt, 'scn:')+5)))); dbms_output.put_line(to_char(line_num, '00000009')||' SCN '||hex2scnbw(cr_scn_hex)||' (HEX '||cr_scn_hex||')'); ELSIF trc_txt LIKE 'END OF STMT%' THEN trc_sql_statement := FALSE; ELSIF trc_sql_statement = TRUE THEN dbms_output.put_line(TRIM(trc_txt)); ELSIF trc_txt LIKE 'PARSING IN CURSOR%' THEN trc_sql_statement := TRUE; dbms_output.put_line(CHR(10)); END IF; END LOOP; END; /
Fink & Deshpande
Page 14
Tracing Logical IOs
Other commands To dump the contents of a data buffer, you have to perform two commands. alter session set events ‘immediate trace name set_tsn_p1 level <ts#+1>’; alter session set events ‘immediate trace name buffer level <dba>’;
dba is the decimal value of the datablock address. Within the trace output, the datablock address is written as a hexdecimal value and can be converted to a decimal value using the hex2dec function.
Fink & Deshpande
Page 15