From oracle-l-bounce@freelists.org Mon Jun 7 13:44:08 2004 Return-Path: Received: from air189.startdedicated.com (root@localhost) by orafaq.com (8.11.6/8.11.6) with ESMTP id i57IhqA19584 for ; Mon, 7 Jun 2004 13:44:02 -0500 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 i57Iha619430 for ; Mon, 7 Jun 2004 13:43:47 -0500 Received: from localhost (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 6C99A72C80F; Mon, 7 Jun 2004 13:29:24 -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 29623-18; Mon, 7 Jun 2004 13:29:24 -0500 (EST) Received: from turing (localhost [127.0.0.1]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 677C972C81A; Mon, 7 Jun 2004 13:29:23 -0500 (EST) Received: with ECARTIS (v1.0.0; list oracle-l); Mon, 07 Jun 2004 13:28:03 -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 2DCCB72C7C6 for ; Mon, 7 Jun 2004 13:28:03 -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 29009-37 for ; Mon, 7 Jun 2004 13:28:02 -0500 (EST) Received: from notessv1.medidata.com.br (usern.medidata.com.br [200.244.48.3]) by turing.freelists.org (Avenir Technologies Mail Multiplex) with ESMTP id 45BDA72C7D3 for ; Mon, 7 Jun 2004 13:28:02 -0500 (EST) Subject: Help on Oraperf YAPP analyzer To: oracle-l@freelists.org X-Mailer: Lotus Notes Release 5.0.8 June 18, 2001 Message-ID: From: robson@medidata.com.br Date: Mon, 7 Jun 2004 15:46:05 -0300 X-MIMETrack: Serialize by Router on NOTES_SV1/MLX(Release 5.0.8 |June 18, 2001) at 07/06/2004 15:46:13 MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Transfer-Encoding: 8bit X-MIME-Autoconverted: from quoted-printable to 8bit by Ecartis X-Virus-Scanned: by amavisd-new at freelists.org X-archive-position: 2144 X-ecartis-version: Ecartis v1.0.0 Sender: oracle-l-bounce@freelists.org Errors-To: oracle-l-bounce@freelists.org X-original-sender: robson@medidata.com.br Precedence: normal Reply-To: oracle-l@freelists.org X-list: oracle-l X-Virus-Scanned: by amavisd-new at freelists.org Hi This is my fitst post to the list. I used the oraperf analyzer on some 8.1.7.4 statspack reports and found different results from the ones I got last year. Comparing results for the same statspack reports I could locate the source of the difference: On the response time calculation, now but not before, the wait times are being multiplied by 100. This gives one amount of wait time two orders of magnitude greater than the cpu times, and biases the response times as being dominated by huge wait times. Does someone noted this behavior change? Any help is appreciated Below are the excerpts of the YAPP oraperf output from the same statspack report: Old report Breakdown of Response Time |------------+------+----------+---------+----------+------------| | | Time | Percentag| Per | Per User | Per | | | | e | Execute | Call | Transaction| |------------+------+----------+---------+----------+------------| | Response | | | | | | | Time | | | | | | |------------+------+----------+---------+----------+------------| | Response | 77712| 100.00%| 0.61| 0.34| 15.68| | Time | 9| | | | | |------------+------+----------+---------+----------+------------| | CPU Time | 42197| 54.30%| 0.33| 0.19| 8.51| | | 6| | | | | |------------+------+----------+---------+----------+------------| | Wait Time | 35515| 45.70%| 0.28| 0.16| 7.17| | | 3| | | | | |------------+------+----------+---------+----------+------------| New report I think here the wait time is inflated by a factor times 100: Breakdown of Response Time |------------+--------+----------+---------+----------+------------| | | Time | Percentag| Per | Per User | Per | | | | e | Execute | Call | Transaction| |------------+--------+----------+---------+----------+------------| | Response | | | | | | | Time | | | | | | |------------+--------+----------+---------+----------+------------| | Response | 3593727| 100.00%| 28.17| 15.87| 725.05| | Time | 6| | | | | |------------+--------+----------+---------+----------+------------| | CPU Time | 421976| 1.17%| 0.33| 0.19| 8.51| |------------+--------+----------+---------+----------+------------| | Wait Time | 3551530| 98.83%| 27.84| 15.69| 716.54| | | 0| | | | | |------------+--------+----------+---------+----------+------------| If you look on the wait time break down now all times are times 100: Breakdown of Wait Time The wait for the foreground sessions can be broken down in the following wait events (in order of wait time): |---------------------+--------+----------+--------+---------+----------+------------| | Event | Time | Percentag| Avg. | Per | Per User | Per | | | | e | Wait | Execute | Call | Transaction| |---------------------+--------+----------+--------+---------+----------+------------| | Wait Time | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | log file sync | 2195490| 61.82%| 97.69| 17.21| 9.70| 442.95| | | 0| | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | db file sequential | 9333600| 26.28%| 3.34| 7.32| 4.12| 188.31| | read | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | direct path write | 1866800| 5.26%| 1026.28| 1.46| 0.82| 37.66| |---------------------+--------+----------+--------+---------+----------+------------| | db file scattered | 811000| 2.28%| 17.67| 0.64| 0.36| 16.36| | read | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net more data to| 345200| 0.97%| 52.60| 0.27| 0.15| 6.96| | client | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | direct path read | 323700| 0.91%| 74.83| 0.25| 0.14| 6.53| |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net message from| 252400| 0.71%| 32.61| 0.20| 0.11| 5.09| | dblink | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | latch free | 196600| 0.55%| 26.68| 0.15| 0.09| 3.97| |---------------------+--------+----------+--------+---------+----------+------------| | control file | 124400| 0.35%| 51.68| 0.10| 0.05| 2.51| | parallel write | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net break/reset | 77600| 0.22%| 2.72| 0.06| 0.03| 1.57| | to clien | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net more data | 67900| 0.19%| 2.82| 0.05| 0.03| 1.37| | from dblin | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | log file sequential | 58200| 0.16%| 3.03| 0.05| 0.03| 1.17| | read | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net message to | 53500| 0.15%| 0.02| 0.04| 0.02| 1.08| | client | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | file open | 22800| 0.06%| 6.71| 0.02| 0.01| 0.46| |---------------------+--------+----------+--------+---------+----------+------------| | enqueue | 7500| 0.02%| 250.00| 0.01| 0.00| 0.15| |---------------------+--------+----------+--------+---------+----------+------------| | log file switch | 4000| 0.01%| 571.43| 0.00| 0.00| 0.08| | completion | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | buffer busy waits | 3900| 0.01%| 9.22| 0.00| 0.00| 0.08| |---------------------+--------+----------+--------+---------+----------+------------| | refresh controlfile | 2700| 0.01%| 2.10| 0.00| 0.00| 0.05| | command | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | control file | 2700| 0.01%| 0.38| 0.00| 0.00| 0.05| | sequential read | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net more data | 2600| 0.01%| 0.45| 0.00| 0.00| 0.05| | from clien | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | library cache pin | 1600| 0.00%| 800.00| 0.00| 0.00| 0.03| |---------------------+--------+----------+--------+---------+----------+------------| | direct path read | 700| 0.00%| 1.55| 0.00| 0.00| 0.01| | (lob) | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | log file single | 600| 0.00%| 100.00| 0.00| 0.00| 0.01| | write | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net message to | 300| 0.00%| 0.04| 0.00| 0.00| 0.01| | dblink | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| | file identify | 100| 0.00%| 6.67| 0.00| 0.00| 0.00| |---------------------+--------+----------+--------+---------+----------+------------| | SQL*Net break/reset | 0| 0.00%| 0.00| 0.00| 0.00| 0.00| | to dblin | | | | | | | |---------------------+--------+----------+--------+---------+----------+------------| Robson Gomes Medidata Informática S.A ---------------------------------------------------------------- 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 -----------------------------------------------------------------