Home » RDBMS Server » Performance Tuning » I/O cost was very high (Windows Server 2003, Oracle 10.2.0.4)
I/O cost was very high [message #421528] Wed, 09 September 2009 01:33 Go to next message
trantuananh24hg
Messages: 668
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Dear all!
I've got one query, that executed for 225(s). And I post here, including explanation, tkprof result, tab_stats, hope you will give me some advancements

1. Time in second parsed/executed/fetched to result
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

logtinhcuoc@TINHCUOC> alter session set sql_trace=true;

Session altered.

logtinhcuoc@TINHCUOC> set feedback off
logtinhcuoc@TINHCUOC> alter session set events '10046 trace name context forever
, level 12';
logtinhcuoc@TINHCUOC> var chugoi varchar2(30);
logtinhcuoc@TINHCUOC> begin
  2  :chugoi:='84918151446';
  3  end;
  4  /
logtinhcuoc@TINHCUOC> select/*+parallel_index(ccs_hcm.idx_ctdd_20090501,5)*/ chu
goi, gio_bd, tg_goi, bigoi,
  2          ten_vung, tien_tn, tien_qt,tien_qt_vnd,
  3          ghichu,tien_mienphi_tn,
  4          tien_khongthue,khoanmuctc_id,tien_dv
  5  from ccs_hcm.ctdd_20090501
  6  where chugoi=:chugoi;

-- tkprof --
select/*+parallel_index(ccs_hcm.idx_ctdd_20090501,5)*/ chugoi, gio_bd, tg_goi, bigoi,
        ten_vung, tien_tn, tien_qt,tien_qt_vnd,
        ghichu,tien_mienphi_tn,
        tien_khongthue,khoanmuctc_id,tien_dv
from ccs_hcm.ctdd_20090501
where chugoi=:chugoi

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.17          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch       57      1.76     215.06      27313      51106          0         841
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       59      1.76     215.23      27313      51106          0         841

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 127  

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      57        0.00          0.00
  db file sequential read                     41263        0.44        299.77
  SQL*Net message from client                    57        0.84          2.51
  db file parallel read                          55        0.04          1.31


Explanation sql plan:
logtinhcuoc@TINHCUOC> set autotrace traceonly explain
logtinhcuoc@TINHCUOC> select/*+parallel_index(ccs_hcm.idx_ctdd_20090501,5)*/ chu
goi, gio_bd, tg_goi, bigoi,
  2          ten_vung, tien_tn, tien_qt,tien_qt_vnd,
  3          ghichu,tien_mienphi_tn,
  4          tien_khongthue,khoanmuctc_id,tien_dv
  5  from ccs_hcm.ctdd_20090501
  6  where chugoi=:chugoi
  7  /

Execution Plan
----------------------------------------------------------
Plan hash value: 3750483198

--------------------------------------------------------------------------------
-----------------
| Id  | Operation                   | Name              | Rows  | Bytes | Cost (
%CPU)| Time     |
--------------------------------------------------------------------------------
-----------------
|   0 | SELECT STATEMENT            |                   |   511 | 47012 | 71661
  (1)| 00:14:20 |
|   1 |  TABLE ACCESS BY INDEX ROWID| CTDD_20090501     |   511 | 47012 | 71661
  (1)| 00:14:20 |
|*  2 |   INDEX SKIP SCAN           | IDX_CTDD_20090501 |   517 |       | 71208
  (1)| 00:14:15 |
--------------------------------------------------------------------------------
-----------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("CHUGOI"=:CHUGOI)
       filter("CHUGOI"=:CHUGOI)



Table statistics, index statistics, datafiles
logtinhcuoc@TINHCUOC> col index_name format a18
logtinhcuoc@TINHCUOC> col table_name format a16
logtinhcuoc@TINHCUOC> select index_name, index_type, table_name
  2  from dba_indexes
  3  where owner='CCS_HCM'
  4  and table_name='CTDD_20090501';

INDEX_NAME         INDEX_TYPE                  TABLE_NAME
------------------ --------------------------- ----------------
IDX_CTDD_20090501  NORMAL                      CTDD_20090501

logtinhcuoc@TINHCUOC> select owner,table_name,last_analyzed,
  2  global_stats gblstats, user_stats usrstats,
  3  num_rows
  4  from dba_tab_statistics
  5  where owner='CCS_HCM'
  6  and table_name='CTDD_20090501'
  7  /

OWNER                          TABLE_NAME       LAST_ANAL GBL USR   NUM_ROWS
------------------------------ ---------------- --------- --- --- ----------
CCS_HCM                        CTDD_20090501    21-AUG-09 YES NO    36317050


logtinhcuoc@TINHCUOC> select count(1)
  2  from ccs_hcm.ctdd_20090501
  3  /

                      COUNT(1)
------------------------------
                      36319677

logtinhcuoc@TINHCUOC> col tablespace format a10
logtinhcuoc@TINHCUOC> col filename format a30
logtinhcuoc@TINHCUOC> set numwidth 30
logtinhcuoc@TINHCUOC> set pagesize 500
logtinhcuoc@TINHCUOC> set linesize 250
logtinhcuoc@TINHCUOC> select tablespace, filename, filesize
  2  from tablespace_info
  3  where tablespace='USERS';

TABLESPACE FILENAME                                             FILESIZE
---------- ------------------------------ ------------------------------
USERS      D:\TINHCUOCDATAFILES\USERS01.D                    28767682560
           BF

USERS      D:\TINHCUOCDATAFILES\USERS02.D                    21474836480
           BF

USERS      D:\TINHCUOCDATAFILES\USERS03.D                    21474836480
           BF

USERS      D:\TINHCUOCDATAFILES\USERS11.D                    32212254720
           BF

USERS      F:\TINHCUOCDATAFILES\USERS04.D                    21474836480
           BF

USERS      F:\TINHCUOCDATAFILES\USERS05.D                    21474836480
           BF

USERS      F:\TINHCUOCDATAFILES\USERS06.D                    21474836480
           BF

USERS      F:\TINHCUOCDATAFILES\USERS11.D                    32212254720
           BF

USERS      F:\TINHCUOCDATAFILES\USERS12.D                    32212254720
           BF

USERS      G:\TINHCUOCDATAFILES\USERS07.D                    21474836480
           BF

USERS      G:\TINHCUOCDATAFILES\USERS08.D                    32212254720
           BF

USERS      G:\TINHCUOCDATAFILES\USERS09.D                    32212254720
           BF

USERS      G:\TINHCUOCDATAFILES\USERS10.D                    32212254720
           BF


13 rows selected.

logtinhcuoc@TINHCUOC>


Index on columns
logtinhcuoc@TINHCUOC> select dbms_metadata.get_ddl('INDEX','IDX_CTDD_20090501','
CCS_HCM') from dual;

DBMS_METADATA.GET_DDL('INDEX',
--------------------------------------------------------------------------------


  CREATE INDEX "CCS_HCM"."IDX_CTDD_20090501" ON "CCS_HCM"."CTDD_20090501" ("MA_K

H", "CHUGOI", "GIO_BD")
  PCTFREE 10 INITRANS 2 MAXTRANS 255 NOLOGGING COMPUTE STATISTICS
  STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
  PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT)
  TABLESPACE "USERS"




[Updated on: Wed, 09 September 2009 02:11]

Report message to a moderator

Re: I/O cost was very high [message #421549 is a reply to message #421528] Wed, 09 September 2009 03:14 Go to previous messageGo to next message
JRowbottom
Messages: 5933
Registered: June 2006
Location: Sunny North Yorkshire, ho...
Senior Member
From the trace, it looks like the query was run 57 times, taking a total time of 215 seconds.

Are you by any chance calling this query several times in a loop?

[thanks for providing a good spread of information]

{added thanks}

[Updated on: Wed, 09 September 2009 03:16]

Report message to a moderator

Re: I/O cost was very high [message #421553 is a reply to message #421549] Wed, 09 September 2009 04:01 Go to previous messageGo to next message
trantuananh24hg
Messages: 668
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Dear J!

This is a single query I've executed by myself.

Of course, in a App, there are not only one-by-one single, but also complexes sessions from Middle Tier, Dev(s), ... About 140 times executing concurrently 16 hours ago, and I must use resource_manager to limit to 4 concurrent sessions per user, the only way that I did till now.

I can capture by image and post here, step-by-step, if you need.

One idea was highlighted at my mind "The I/O cost was high, because of many reasons, file_system is one, chained_row could be one, heap table designed could be one". But, in OLTP, it's not hard to re-design, not easily to change heap table to partitioned_table, and it's not easily to change file_system to ASM".

I need more than everything I can think, so that, I need you.

Thank you!

[Updated on: Wed, 09 September 2009 04:03]

Report message to a moderator

Re: I/O cost was very high [message #421701 is a reply to message #421528] Wed, 09 September 2009 22:27 Go to previous message
trantuananh24hg
Messages: 668
Registered: January 2007
Location: Ha Noi, Viet Nam
Senior Member
Today, I upload step-by-step images here, hope you help me to identify what's problem.

1. The query ( I used OEM, instead of v$session_longops)
http://i95.photobucket.com/albums/l130/trantuananh24hg/1.jpg

2. Tracing query
http://i95.photobucket.com/albums/l130/trantuananh24hg/2.jpg

3. Result
http://i95.photobucket.com/albums/l130/trantuananh24hg/3-1.jpg

4. Off feedback, termout
http://i95.photobucket.com/albums/l130/trantuananh24hg/4.jpg

5. Identified PID in udump
http://i95.photobucket.com/albums/l130/trantuananh24hg/5.jpg

6. Recheck if PID was right
http://i95.photobucket.com/albums/l130/trantuananh24hg/6.jpg

7. Tkprof
http://i95.photobucket.com/albums/l130/trantuananh24hg/7.jpg

You'll see, the fetch column was 27, but only one my session

Thank you!
Previous Topic: DBMS_STATS running slow.
Next Topic: Use of DBMS_LOGSTDBY
Goto Forum:
  


Current Time: Sat Dec 03 18:04:37 CST 2016

Total time taken to generate the page: 0.04366 seconds