From oracle-l-bounce@freelists.org Tue Mar 30 15:48:27 2004 Return-Path: Received: from air189.startdedicated.com (root@localhost) by orafaq.com (8.11.6/8.11.6) with ESMTP id i2ULmRO23277 for ; Tue, 30 Mar 2004 15:48:27 -0600 X-ClientAddr: 206.53.239.180 Received: from turing.freelists.org (freelists-180.iquest.net [206.53.239.180]) by air189.startdedicated.com (8.11.6/8.11.6) with ESMTP id i2ULmOo23271 for ; Tue, 30 Mar 2004 15:48:25 -0600 Received: from localhost (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id D0E186348F1; Tue, 30 Mar 2004 16:43:00 -0500 (EST) Received: from turing.freelists.org ([127.0.0.1]) by localhost (turing [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 21467-13; Tue, 30 Mar 2004 16:43:00 -0500 (EST) Received: from turing (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 24C0263479A; Tue, 30 Mar 2004 16:43:00 -0500 (EST) Received: with ECARTIS (v1.0.0; list oracle-l); Tue, 30 Mar 2004 16:41:49 -0500 (EST) X-Original-To: oracle-l@freelists.org Delivered-To: oracle-l@freelists.org Received: from localhost (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 953E463471D for ; Tue, 30 Mar 2004 16:41:48 -0500 (EST) Received: from turing.freelists.org ([127.0.0.1]) by localhost (turing [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 19472-80 for ; Tue, 30 Mar 2004 16:41:48 -0500 (EST) Received: from hero.affina.net (mailout.affina.com [12.20.72.25]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id A1ACD634112 for ; Tue, 30 Mar 2004 16:41:47 -0500 (EST) Received: by hero.affina.net with Internet Mail Service (5.5.2653.19) id ; Tue, 30 Mar 2004 15:49:56 -0600 Message-ID: <4A82CFCF30FDD211A7960008C7B1917023696972@hero.affina.net> From: Chris Stephens To: "'oracle-l@freelists.org'" Subject: RE: Database sloowww...trying to figure out why... Date: Tue, 30 Mar 2004 15:49:55 -0600 MIME-Version: 1.0 X-Mailer: Internet Mail Service (5.5.2653.19) Content-Type: multipart/alternative; boundary="----_=_NextPart_001_01C416A0.F04998B0" X-Virus-Scanned: by amavisd-new at freelists.org X-archive-position: 2116 X-ecartis-version: Ecartis v1.0.0 Sender: oracle-l-bounce@freelists.org Errors-To: oracle-l-bounce@freelists.org X-original-sender: ChrisStephens@affina.com Precedence: normal Reply-To: oracle-l@freelists.org X-list: oracle-l X-Virus-Scanned: by amavisd-new at freelists.org ------_=_NextPart_001_01C416A0.F04998B0 Content-Type: text/plain I thought that was a possibility too. The buffer cache is over a gig...the entire database is around 50 gig. ...I haven't seen any swapping on the machine. -----Original Message----- From: Goulet, Dick [mailto:DGoulet@vicr.com] Sent: Tuesday, March 30, 2004 3:40 PM To: oracle-l@freelists.org Subject: RE: Database sloowww...trying to figure out why... Shot from the hip here, but it would sound like your vendor has the buffer cache up way too high in the first place. Sure the swapper isn't having a field day? Dick Goulet Senior Oracle DBA Oracle Certified 8i DBA -----Original Message----- From: Chris Stephens [mailto:ChrisStephens@affina.com] Sent: Tuesday, March 30, 2004 4:24 PM To: oracle-l@freelists.org Subject: Database sloowww...trying to figure out why... Well, what can I say...more performance problems in our apps environment. The outsourcing company is suggesting things like increasing buffer cache (seriously!). This time I've successfully campaigned to alteast get perfstat installed on the prod db. Here is what I've found so far. After taking several snapshots it appears we have a cpu issue (sort of...it's weird because the slowaris box doesn't look stressed for cpa AT ALL!). As much as 80% of the response time is due to cpu usage. ...of that cpu usage the majority of it is 'other cpu'. Absolutely everything I try to do in there is slow (mostly look ups on the data dictionary to try and figure out what's wrong). Without the ability to trace user sessions, I thought I would trace my own. Executing statspack.snap takes as much as 25 seconds!!! So I enable 10046 trace and formatted the trace file through tkprof. The database is 9203. The biggest waits in the trace file are due to the execute phase. Here is an example: INSERT into stats$sql_summary ( snap_id , dbid , instance_number , text_subset , sharable_mem , sorts , module , loaded_versions , fetches , executions , loads , invalidations , parse_calls , disk_reads , buffer_gets , rows_processed , command_type , address , hash_value , version_count , cpu_time , elapsed_time , outline_sid , outline_category , child_latch ) select :b9 , :b8 , :b7 , substrb(sql_text,1,31) , sharable_mem , sorts , module , loaded_versions , fetches , executions , loads , invalidations , parse_calls , disk_reads , buffer_gets , rows_processed , command_type , address , hash_value , version_count , cpu_time , elapsed_time , outline_sid , outline_category , child_latch from stats$v$sqlxs where is_obsolete = 'N' and ( buffer_gets > :b6 or disk_reads > :b5 or parse_calls > :b4 or executions > :b3 or sharable_mem > :b2 or version_count > :b1 ) call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.07 0.07 0 0 0 0 Execute 1 5.27 5.27 0 398 2738 6041 Fetch 0 0.00 0.00 0 0 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 2 5.34 5.35 0 398 2738 6041 Misses in library cache during parse: 1 Optimizer goal: CHOOSE Parsing user id: 266 (recursive depth: 1) Rows Row Source Operation ------- --------------------------------------------------- 6041 VIEW (cr=0 r=0 w=0 time=4815086 us) 6041 FILTER (cr=0 r=0 w=0 time=4805641 us) 30284 SORT GROUP BY (cr=0 r=0 w=0 time=4760583 us) 33809 FIXED TABLE FULL X$KGLCURSOR (cr=0 r=0 w=0 time=3106069 us) Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ control file sequential read 24 0.00 0.00 db file sequential read 4 0.00 0.00 async disk IO 2 0.00 0.01 db file single write 2 0.00 0.00 control file parallel write 4 0.00 0.00 rdbms ipc reply 2 0.00 0.00 I'm not so good at looking at raw trace files so I'm not sure what part of that is relevant and what's not. I guess what I'm asking is that now that I know that much of our database time is spent on cpu and it appears (at least in my case) that much of that is the execute phase where should I go from hear? ...I would imagine there's a plethora of info in the raw trace file that I'm not privi to due to ignorance. ...in my defense, I did try getting the miracle 10046 doohickey to work but have given up because I'm on hp not red hat and I can't figure out what the equivalent of 'ls -l --time=atime *' is in ksh. ...and then it's not guaranteed to work because of possible differences in trace file format between red hat and hp. If anyone would like to see the full trace file, I have attached that. Thanks for any help. Anyone know of a 10046 parser that works in an hp environment? Chris ------_=_NextPart_001_01C416A0.F04998B0 Content-Type: text/html

I thought that was a possibility too.

 

The buffer cache is over a gig...the entire database is around 50 gig.

 

...I haven't seen any swapping on the machine.

 

 

 

-----Original Message-----
From: Goulet, Dick [mailto:DGoulet@vicr.com]
Sent: Tuesday, March 30, 2004 3:40 PM
To: oracle-l@freelists.org
Subject: RE: Database sloowww...trying to figure out why...

 

Shot from the hip here, but it would sound like your vendor has the buffer cache up way too high in the first place.  Sure the swapper isn't having a field day?

 

Dick Goulet
Senior Oracle DBA
Oracle Certified 8i DBA

-----Original Message-----
From: Chris Stephens [mailto:ChrisStephens@affina.com]
Sent: Tuesday, March 30, 2004 4:24 PM
To: oracle-l@freelists.org
Subject: Database sloowww...trying to figure out why...

Well, what can I say...more performance problems in our apps environment.  The outsourcing company is suggesting things like increasing buffer cache (seriously!).

 

This time I've successfully campaigned to alteast get perfstat installed on the prod db.  Here is what I've found so far.

 

After taking several snapshots it appears we have a cpu issue (sort of...it's weird because the slowaris box doesn't look stressed for cpa AT ALL!).  As much as 80% of the response time is due to cpu usage.  ...of that cpu usage the majority of it is 'other cpu'.   Absolutely everything I try to do in there is slow (mostly look ups on the data dictionary to try and figure out what's wrong).  Without the ability to trace user sessions, I thought I would trace my own.  Executing statspack.snap takes as much as 25 seconds!!!  So I enable 10046 trace and formatted the trace file through tkprof.  The database is 9203.  The biggest waits in the trace file are due to the execute phase.  Here is an example:

 

INSERT into stats$sql_summary

            ( snap_id

            , dbid

            , instance_number

            , text_subset

            , sharable_mem

            , sorts

            , module

            , loaded_versions

            , fetches

            , executions

            , loads

            , invalidations

            , parse_calls

            , disk_reads

            , buffer_gets

            , rows_processed

            , command_type

            , address

            , hash_value

            , version_count

            , cpu_time

            , elapsed_time

            , outline_sid

            , outline_category

            , child_latch

            )

       select :b9

            , :b8

            , :b7

            , substrb(sql_text,1,31)

            , sharable_mem

            , sorts

            , module

            , loaded_versions

            , fetches

            , executions

            , loads

            , invalidations

            , parse_calls

            , disk_reads

            , buffer_gets

            , rows_processed

            , command_type

            , address

            , hash_value

            , version_count

            , cpu_time

            , elapsed_time

            , outline_sid

            , outline_category

            , child_latch

         from stats$v$sqlxs

        where is_obsolete = 'N'

          and (   buffer_gets   > :b6

               or disk_reads    > :b5

               or parse_calls   > :b4

               or executions    > :b3

               or sharable_mem  > :b2

               or version_count > :b1

              )

 

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse       1      0.07       0.07          0          0          0           0

Execute    1      5.27       5.27          0        398       2738        6041

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      5.34       5.35          0        398       2738        6041

 

Misses in library cache during parse: 1

Optimizer goal: CHOOSE

Parsing user id: 266     (recursive depth: 1)

 

Rows     Row Source Operation

-------  ---------------------------------------------------

   6041  VIEW  (cr=0 r=0 w=0 time=4815086 us)

   6041   FILTER  (cr=0 r=0 w=0 time=4805641 us)

  30284    SORT GROUP BY (cr=0 r=0 w=0 time=4760583 us)

  33809     FIXED TABLE FULL X$KGLCURSOR (cr=0 r=0 w=0 time=3106069 us)

 

 

Elapsed times include waiting on following events:

  Event waited on                             Times   Max. Wait  Total Waited

  ----------------------------------------   Waited  ----------  ------------

  control file sequential read              24        0.00          0.00

  db file sequential read                      4        0.00          0.00

  async disk IO                                  2        0.00          0.01

  db file single write                            2        0.00          0.00

  control file parallel write                    4        0.00          0.00

  rdbms ipc reply                                2        0.00          0.00

 

 

I'm not so good at looking at raw trace files so I'm not sure what part of that is relevant and what's not. 

 

I guess what I'm asking is that now that I know that much of our database time is spent on cpu and it appears (at least in my case) that much of that is the execute phase where should I go from hear?  ...I would imagine there's a plethora of info in the raw trace file that I'm not privi to due to ignorance.  ...in my defense, I did try getting the miracle 10046 doohickey to work but have given up because I'm on hp not red hat and I can't figure out what the equivalent of  'ls -l --time=atime *' is in ksh.  ...and then it's not guaranteed to work because of possible differences in trace file format between red hat and hp. 

 

If anyone would like to see the full trace file, I have attached that.

 

Thanks for any help.

 

Anyone know of a 10046 parser that works in an hp environment?

 

Chris

------_=_NextPart_001_01C416A0.F04998B0-- ---------------------------------------------------------------- Please see the official ORACLE-L FAQ: http://www.orafaq.com ---------------------------------------------------------------- To unsubscribe send email to: oracle-l-request@freelists.org put 'unsubscribe' in the subject line. -- Archives are at http://www.freelists.org/archives/oracle-l/ FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html -----------------------------------------------------------------