HelloDBA [中文]
Search Internet Search HelloDBA
  Oracle Technology Site. email: fuyuncat@gmail.com  MSN: fuyuncat@hotmail.com Add to circle  acoug  acoug 

Secret of oracle logic IO: Sorting


Author:  fuyuncat

Source:  www.HelloDBA.com

Date:  2009-11-10 01:14:31

Share to  Twitter Facebook GMail Blogger Orkut Google Bookmarks Sina Weibo QQ Renren Tieba Kaixin Douban Taobao

    In this case, I will involve the sorting.

  1. HELLODBA.COM>conn demo/demo   
  2. Connected.   
  3. HELLODBA.COM>alter system flush buffer_cache;   
  5. System altered.   
  7. HELLODBA.COM>ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';   
  9. Session altered.   
  11. HELLODBA.COM>set autot trace stat   
  12. HELLODBA.COM>select * from t_test2 order by table_name;   
  14. 2072 rows selected.   
  16. Statistics  
  17. ----------------------------------------------------------   
  18.           7  recursive calls   
  19.          21  db block gets   
  20.          65  consistent gets   
  21.         201  physical reads   
  22.           0  redo size  
  23.      131049  bytes sent via SQL*Net to client   
  24.        1903  bytes received via SQL*Net from client   
  25.         140  SQL*Net roundtrips to/from client   
  26.           0  sorts (memory)   
  27.           1  sorts (disk)   
  28.        2072  rows processed  

    Review the trace file, we can get the Logical reads number: 62 data block rows fetching + 3 segment header reads = 65.

    Check the file in detail, you will found the FETCH came after all the sorting operation completed, that means the arraysize will not affect the data block reads, so, each of the data block was just read once in this case! compare to the previous test case that query the same table without sorting, its Logical reads is lower.

    Since this case involved the sorting, we can find below new entries,

  1. pin stswh00: stsswr dba 402f3f:2 time 857155584   
  2. pin release        43 stswh00: stsswr dba 402f3f:2   
  3. WAIT #2: nam='direct path write temp' ela= 0 file number=201 first dba=12080 block cnt=1 obj#=97820 tim=857155720  

    It's not hard to guess the stsswr is the operation to write sorting data in temp segments. Since it's to write data, it's counted as db block gets. There are 21 db block gets.

  1. C:\oracle\product\10.2.0\admin\hellodba.com>set /a a=0   
  2. 0   
  3. C:\oracle\product\10.2.0\admin\hellodba.com>for /f "tokens=1 delims=:" %i in ('findstr /C:"pin stswh00" C:\oracle\product\10.2.0\admin\edgar\udump\LIO_Sort.trc') do @set /a a+=1 > NUL   
  5. C:\oracle\product\10.2.0\admin\hellodba.com>echo %a%   
  6. 21  

    Read all of the sorting operation entries, we can find all of them wrote into the same block, so there was just 1 sorts in disk.

  1. pin stswh00: stsswr dba 402f3f:2 time 857147806   
  2. ...   
  3. pin stswh00: stsswr dba 402f3f:2 time 857255971   
  4. pin stswh00: stsswr dba 402f3f:2 time 857256077  

    Finally, let's calculate the physical reads. By counting the "db file sequential read" & "db file scattered read" waits blocks, we get 63 PIO. Then count the "direct path read temp", we get the other 138 PIO.

  1. C:\oracle\product\10.2.0\admin\hellodba.com>set /a a=0   
  2. 0   
  3. C:\oracle\product\10.2.0\admin\hellodba.com>for /f "tokens=1 delims=:" %i in ('findstr /C:"direct path read temp" C:\oracle\product\10.2.0\admin\edgar\udump\LIO_Sort.trc') do @set /a a+=1 > NUL   
  5. C:\oracle\product\10.2.0\admin\hellodba.com>echo %a%   
  6. 138  

    Btw, in other test cases with same process, I noted sometimes the "direct path read temp" number is more than excepted, I still not found the reason, just guess it may caused by the recursive calls.

    --- Fuyuncat TBC ---


Copyright ©2005, HelloDBA.Com All reseverd.

by fuyuncat