Query Execution Call Stack Trace

[中文]

Author:  fuyuncat

Source:  www.HelloDBA.com

Date:  2010-05-12 09:54:07

Share to 

As we know, an execution plan decides the functions that access data / generate row source / process row sources. With tracing the call stacks, we can find the internal funcions mapping to execution plan operations.       First, with a simple sql that have full table scan on a small table. SQL代码 HELLODBA.COM>select owner, table_name from demo.T_TEST2 t where table_name like 'T%';       OWNER                          TABLE_NAME    ------------------------------ ------------------------------    SYS                            TS$    SYS                            TSQ$    SYS                            TYPE_MISC$    SYS                            TAB$    SYS                            TYPED_VIEW$    SYS                            TRIGGER$    SYS                            TRIGGERCOL$    SYS                            TRIGGERJAVAF$    SYS                            TRIGGERJAVAS$    SYS                            TRIGGERJAVAC$    SYS                            TRIGGERJAVAM$    SYS                            TRUSTED_LIST$    SYS                            TYPE$    SYS                            TYPEHIERARCHY$    SYS                            TABPART$    SYS                            TABSUBPART$    SYS                            TABCOMPART$    SYS                            TABLE_PRIVILEGE_MAP    SYS                            TAB_STATS$    SYS                            TSM_SRC$    SYS                            TSM_DST$    SYS                            TRANSFORMATIONS$       22 rows selected.          Execution Plan    ----------------------------------------------------------    Plan hash value: 1680898452       -----------------------------------------------------------------------------    | Id  | Operation         | Name    | Rows  | Bytes | Cost (%CPU)| Time     |    -----------------------------------------------------------------------------    |   0 | SELECT STATEMENT  |         |    51 |  1275 |    13   (0)| 00:00:01 |    |*  1 |  TABLE ACCESS FULL| T_TEST2 |    51 |  1275 |    13   (0)| 00:00:01 |    -----------------------------------------------------------------------------       Predicate Information (identified by operation id):    ---------------------------------------------------          1 - filter("TABLE_NAME" LIKE 'T%')        With the trace, it's not hard to find the funcion map to TABLE ACCESS FULL is qertbFetch. The calls number of the funcion correspond to the fetchs number. Except the first row, the limitation of the fetch size is decided by the array_size set in client. For SQL*Plus, default is 15. Take previous case, the fetchs number = 1 + ceil((22-1)/15) = 3. And we can noted there are 3 qertbFetch be traced in the trace file.   SQL代码 (qertbFetch) fetch first row    FETCH #2:c=1000,e=88060877,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=1243700271288837    (qertbRelease)       (qertbFetch) fetch 15 (array size) rows   FETCH #2:c=6999,e=191651765,p=0,cr=4,cu=0,mis=0,r=15,dep=0,og=1,tim=1243700463636714    (qertbRelease)       (qertbFetch) fetch next array (final 6 rows)    FETCH #2:c=2000,e=99456246,p=0,cr=43,cu=0,mis=0,r=6,dep=0,og=1,tim=1243700598805788    (qertbClose)       Then, trace another execution with index scan. SQL代码 HELLODBA.COM>select object_id, object_name, status from demo.t_test1 where owner='DEMO';        OBJECT_ID OBJECT_NAME                                               STATUS     ---------- --------------------------------------------------------- ------------         53085 BIN$hftukXrySqHgQAB/AQBHcw==$0                            VALID           53333 T_TEST1                                                   VALID           53086 T_TEST2                                                   VALID           53320 T_TEST2_IDX1                                              VALID            Execution Plan    ----------------------------------------------------------    Plan hash value: 211562518       -------------------------------------------------------------------------------------------    | Id  | Operation                   | Name        | Rows  | Bytes | Cost (%CPU)| Time     |    -------------------------------------------------------------------------------------------    |   0 | SELECT STATEMENT            |             |     4 |   152 |     5   (0)| 00:00:01 |    |   1 |  TABLE ACCESS BY INDEX ROWID| T_TEST1     |     4 |   152 |     5   (0)| 00:00:01 | ==> qertbFetchByRowID    |*  2 |   INDEX RANGE SCAN          | T_TEST1_UK1 |     4 |       |     2   (0)| 00:00:01 | ==> qerixtFetch     -------------------------------------------------------------------------------------------       Predicate Information (identified by operation id):    ---------------------------------------------------          2 - access("OWNER"='DEMO')       The found function of TABLE ACCESS BY INDEX ROWID is qertbFetchByRowID, and the one of INDEX RANGE SCAN is qerixtFetch. The fetchs number decided the qertbFetchByRowID calls number. And rows number in indexes to be accessed decided the qerixtFetch calls number, with an additional call to decide the ending. SQL代码 (qertbFetchByRowID)    (qerixtFetch)    FETCH #1:c=2000,e=42017935,p=3,cr=3,cu=0,mis=0,r=1,dep=0,og=1,tim=1243777053415112    (qertbRelease)    (qerixRelease)       (qertbFetchByRowID)    (qerixtFetch)    (qerixtFetch)    (qerixtFetch)    FETCH #1:c=2000,e=91247424,p=2,cr=4,cu=0,mis=0,r=3,dep=0,og=1,tim=1243777172136097    (qerixtFetch)    (qertbClose)    (qerixClose)       Note: once call qertbRelease, the resouces loaded by qertbFetch are released, including the buffer cache. So, even thougth some buffer block read in previous fetch, it will still cause new logic io in the next fetch. In another work, the fetch array size decided the execution plan go through times.    With more traces, we can also find the funcions of JOIN and other operations:   (NESTED LOOPS / MERGE) JOIN  ==> qerjotFetch; HASH JOIN ==> qerhjFetch SORT ==> qersoFetch ... --- Fuyuncat ---