After having published my first article of 2019 I have received feedback I felt like including. With a nod to @fritshoogland, @ChrisAntognini and @FranckPachot.
In the previous post I showed you output of Tanel Poder’s ashtop.sql as proof that direct path reads can occur even if all you do is look up data by primary key. This script touches v$active_session_history, and I’m not getting tired of mentioning that you need to license the system in scope for Enterprise Edition and the Diagnostics Pack to do so.
What I haven’t shown you in more detail in the previous article is what causes these direct path reads. This is what I’ll try to do next. I have started by repeating my test case but added the gather_plan_statistics hint to the statement, resulting in a different SQL ID. Yesterday I noticed that Safari doesn’t show the scroll bar at the bottom of this code snippet other browsers show, I hope output isn’t garbled. I’m using the universal excuse here “it works on my laptop”.
SQL> @xia a66axyw2g6yjb
Display Execution plan in advanced format for sqlid a66axyw2g6yjb
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID a66axyw2g6yjb, child number 0
-------------------------------------
select /*+ gather_plan_statistics CLOB standalone */ * from
martin.orders_clob where order_id = :1
Plan hash value: 3284193906
----------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | | 3 (100)| | 0 |00:00:00.01 | 3 |
| 1 | TABLE ACCESS BY INDEX ROWID| ORDERS_CLOB | 1 | 1 | 137 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 3 |
|* 2 | INDEX UNIQUE SCAN | PK_ORDERS_CLOB | 1 | 1 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 3 |
----------------------------------------------------------------------------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1 / ORDERS_CLOB@SEL$1
2 - SEL$1 / ORDERS_CLOB@SEL$1
Outline Data
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('18.1.0')
DB_VERSION('18.1.0')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
INDEX_RS_ASC(@"SEL$1" "ORDERS_CLOB"@"SEL$1" ("ORDERS_CLOB"."ORDER_ID"))
END_OUTLINE_DATA
*/
Peeked Binds (identified by position):
--------------------------------------
1 - :1 (NUMBER): 519990
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("ORDER_ID"=:1)
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - "ORDER_ID"[NUMBER,22], "ORDERS_CLOB"."ORDER_CLOB"[LOB,4000], "ORDERS_CLOB"."ORDER_DATE"[TIMESTAMP WITH LOCAL TIME
ZONE,11], "ORDERS_CLOB"."ORDER_MODE"[VARCHAR2,8], "ORDERS_CLOB"."CUSTOMER_ID"[NUMBER,22],
"ORDERS_CLOB"."ORDER_STATUS"[NUMBER,22], "ORDERS_CLOB"."ORDER_TOTAL"[NUMBER,22], "ORDERS_CLOB"."SALES_REP_ID"[NUMBER,22],
"ORDERS_CLOB"."PROMOTION_ID"[NUMBER,22], "ORDERS_CLOB"."WAREHOUSE_ID"[NUMBER,22], "ORDERS_CLOB"."DELIVERY_TYPE"[VARCHAR2,15],
"ORDERS_CLOB"."COST_OF_DELIVERY"[NUMBER,22], "ORDERS_CLOB"."WAIT_TILL_ALL_AVAILABLE"[VARCHAR2,15],
"ORDERS_CLOB"."DELIVERY_ADDRESS_ID"[NUMBER,22], "ORDERS_CLOB"."CUSTOMER_CLASS"[VARCHAR2,30],
"ORDERS_CLOB"."CARD_ID"[NUMBER,22], "ORDERS_CLOB"."INVOICE_ADDRESS_ID"[NUMBER,22]
2 - "ORDERS_CLOB".ROWID[ROWID,10], "ORDER_ID"[NUMBER,22]
57 rows selected.
After a few minutes of executing the statement repeatedly, direct path reads are clearly visible again
SELECT
COUNT(*),
event,
session_state
FROM
v$active_session_history ash
WHERE
sql_id = 'a66axyw2g6yjb'
AND sample_time > SYSDATE - 15 / 1440
GROUP BY
event,
session_state
ORDER BY
1 DESC;
COUNT(*) EVENT SESSION
---------- ---------------------------------------- -------
1592 ON CPU
24 direct path read WAITING
6 cursor: pin S WAITING
4 SQL*Net more data to client WAITING
So far so good. Getting back to the original question: what’s causing these? ASH provides the answer to that question as well.
SELECT
COUNT(*),
event,
session_state,
sql_plan_operation
|| ' '
|| sql_plan_options AS what,
CASE
WHEN wait_class IN(
'Application',
'Cluster',
'Concurrency',
'User I/O'
)THEN object_name
ELSE 'undef'
END AS obj
FROM
v$active_session_history ash,
dba_objects o
WHERE
ash.current_obj# = o.object_id
AND sql_id = 'a66axyw2g6yjb'
GROUP BY
event,
session_state,
sql_plan_operation
|| ' '
|| sql_plan_options,
CASE
WHEN wait_class IN(
'Application',
'Cluster',
'Concurrency',
'User I/O'
)THEN object_name
ELSE 'undef'
END
ORDER BY 1 desc;
COUNT(*) EVENT SESSION WHAT OBJ
---------- ---------------------------------------- ------- ------------------------------ ------------------------------
3006 ON CPU SELECT STATEMENT undef
223 ON CPU INDEX UNIQUE SCAN undef
126 ON CPU TABLE ACCESS BY INDEX ROWID undef
50 direct path read WAITING SELECT STATEMENT SYS_LOB0000081921C00002$$
8 cursor: pin S WAITING SELECT STATEMENT SYS_LOB0000081921C00002$$
8 SQL*Net more data to client WAITING SELECT STATEMENT undef
1 ON CPU undef
7 rows selected.
I think you might be getting the idea by now … I can link the segment back to DBA_LOBS, and … it’s the LOB column of ORDERS_CLOB.
SELECT
table_name,
column_name,
segment_name,
cache,
securefile
FROM
dba_lobs
WHERE
segment_name = 'SYS_LOB0000081921C00002$$';
TABLE_NAME COLUMN_NAME SEGMENT_NAME CACHE SEC
--------------- --------------- ------------------------------ ---------- ---
ORDERS_CLOB ORDER_CLOB SYS_LOB0000081921C00002$$ NO YES
QED.
Another option is to query session statistics. I looked at one of the sessions using snapper4.sql but the output was too wide to paste it as text. I’ll resort to the traditional way of doing this:
SELECT
name,
value
FROM
v$sesstat st
NATURAL JOIN v$statname sn
WHERE
st.sid = 128
AND st.value <> 0
AND REGEXP_LIKE(name, '(physical|securefile).*read.*')
ORDER BY
sn.name;
NAME VALUE
----------------------------------------- ----------
physical read IO requests 106836
physical read bytes 875200512
physical read total IO requests 106836
physical read total bytes 875200512
physical reads 106836
physical reads direct 106836
physical reads direct (lob) 106836
securefile direct read bytes 875200512
securefile direct read ops 106836
9 rows selected.
I admit this was a rather manual way of extracting this piece of information, you might be able to get the same data with an ASH report (provided the number of I/O samples against that segment is significant enough to show up). In this context I’d like to recommend planx.sql you can find on Carlos Sierra’s and Mauro Pagano’s github repository. It’s small, lightweight, and incredibly useful.
