This discussion is archived
1 2 3 4 Previous Next 54 Replies Latest reply: Jan 15, 2013 4:29 PM by jgarry RSS

Performance Issue

yxes2013 Newbie
Currently Being Moderated
Hi All

OEL 5.6
Oracle 9.2.0.6

Our applications are running intermittently from slow and ok performance. There are days that the processing from 8am to 5pm is okay and there are days that it is very slow and hanging.
The users are just doing the same thing daily from 8am-5pm.

Yesterday the users did not encounter any performance issues from 8am-5pm. But today they hit again the problem starting 1pm up to evening, until we cancel what they are doing because
they are all hanging and decided to shutdown the database and the reboot machine itself hoping it might help. But then again after the database was restarted and the user started to run their process again it still very slow. Could it be hardware problem anymore?

This is the statspack report yesterday from 2pm-3pm where the performance is good. And the next is the statspack report today from 2pm-2:30pm where the performance problem occurs.
Please help me find the difference or the problem on the 2nd statspack. Your help is very much appreciated. Thanks a lot.

http://www.datafilehost.com/download-49750b9f.html (normal performance)
http://www.datafilehost.com/download-f6c8ebbe.html (bad performance)
If downloading this file...
Uncheck [ ] Use our download manager and get recommended download
Partial display of normal performace statspack report:
STATSPACK report for

DB Name         DB Id    Instance     Inst Num Release     Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
OAPROD        4204192100 OAPROD              1 9.2.0.6.0   NO      oel5.unitrad
                                                                   e.local

              Snap Id     Snap Time      Sessions Curs/Sess Comment
            --------- ------------------ -------- --------- -------------------
Begin Snap:       781 07-Jan-13 14:00:02      205      49.2
  End Snap:       782 07-Jan-13 14:30:03      206      55.5
   Elapsed:               30.02 (mins)

Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:       288M      Std Block Size:          8K
           Shared Pool Size:       288M          Log Buffer:     10,240K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:             28,913.12             17,857.52
              Logical reads:            147,316.27             90,986.49
              Block changes:                208.57                128.82
             Physical reads:             77,818.67             48,062.91
            Physical writes:                  7.28                  4.50
                 User calls:                108.83                 67.22
                     Parses:                103.67                 64.03
                Hard parses:                  2.68                  1.65
                      Sorts:                 47.02                 29.04
                     Logons:                  0.17                  0.10
                   Executes:                516.70                319.13
               Transactions:                  1.62

  % Blocks changed per Read:    0.14    Recursive Call %:     91.28
 Rollback per transaction %:    4.36       Rows per Sort:     23.20

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.48       Redo NoWait %:    100.00
            Buffer  Hit   %:   47.18    In-memory Sort %:    100.00
            Library Hit   %:   99.77        Soft Parse %:     97.42
         Execute to Parse %:   79.94         Latch Hit %:     99.91
Parse CPU to Parse Elapsd %:   43.83     % Non-Parse CPU:     99.66

 Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   91.30   91.40
    % SQL with executions>1:   92.30   97.31
  % Memory for SQL w/exec>1:   90.15   95.15

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                     % Total
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
CPU time                                                        5,152    71.73
db file scattered read                         24,697,470       1,152    16.05
db file sequential read                        12,905,526         733    10.21
log file parallel write                             3,682          48      .66
buffer busy waits                               1,375,553          46      .64
          -------------------------------------------------------------
^LWait Events for DB: OAPROD  Instance: OAPROD  Snaps: 781 -782
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file scattered read         24,697,470          0      1,152      0  8,469.6
db file sequential read        12,905,526          0        733      0  4,425.8
log file parallel write             3,682          0         48     13      1.3
buffer busy waits               1,375,553          0         46      0    471.7
log file sync                       2,109          0         35     17      0.7
db file parallel read                  77          0          7     89      0.0
latch free                          1,210        771          4      3      0.4
control file parallel write           641          0          4      6      0.2
SQL*Net break/reset to clien        3,700          0          1      0      1.3
SQL*Net more data to client        31,307          0          0      0     10.7
library cache pin                      13          0          0     19      0.0
enqueue                                 1          0          0    141      0.0
process startup                        12          0          0      8      0.0
control file sequential read          688          0          0      0      0.2
log file switch completion              3          0          0      4      0.0
db file parallel write              1,626          0          0      0      0.6
db file single write                   14          0          0      0      0.0
undo segment extension              2,151      2,151          0      0      0.7
LGWR wait for redo copy                92          0          0      0      0.0
log file single write                   4          0          0      0      0.0
direct path write                      66          0          0      0      0.0
direct path read                       47          0          0      0      0.0
async disk IO                          14          0          0      0      0.0
log file sequential read                4          0          0      0      0.0
SQL*Net message from client       204,344          0    177,547    869     70.1
queue messages                      4,200      4,200     28,128   6697      1.4
pipe get                            1,349      1,314      5,274   3910      0.5
wakeup time manager                    59         59      1,693  28690      0.0
jobq slave wait                       240        240        703   2930      0.1
SQL*Net more data from clien       54,199          0          2      0     18.6
SQL*Net message to client         204,341          0          0      0     70.1
          -------------------------------------------------------------
^LBackground Wait Events for DB: OAPROD  Instance: OAPROD  Snaps: 781 -782
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
log file parallel write             3,682          0         48     13      1.3
db file sequential read               399          0          4     10      0.1
control file parallel write           613          0          4      6      0.2
rdbms ipc reply                        55          0          0      1      0.0
control file sequential read          339          0          0      0      0.1
db file parallel write              1,626          0          0      0      0.6
LGWR wait for redo copy                92          0          0      0      0.0
buffer busy waits                       6          0          0      0      0.0
log file single write                   4          0          0      0      0.0
direct path read                       47          0          0      0      0.0
latch free                              2          1          0      0      0.0
direct path write                      47          0          0      0      0.0
log file sequential read                4          0          0      0      0.0
rdbms ipc message                  16,695      2,366      8,731    523      5.7
smon timer                            457          0      1,781   3898      0.2
pmon timer                            611        611      1,758   2877      0.2
          -------------------------------------------------------------
^LSQL ordered by Gets for DB: OAPROD  Instance: OAPROD  Snaps: 781 -782
-> End Buffer Gets Threshold:     10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
   total % to exceed 100

                                                     CPU      Elapsd
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
    170,415,700            7   24,345,100.0   64.2  2293.46   2335.60  205460129
Module: JDBC Thin Client
select  TRANSACTION_BRANCH , BRANCH_ADDRESS_1 , BRANCH_ADDRESS_2
 , BRANCH_PHONES , BRANCH_FAX , BRANCH_TIN , TRX_NUMBER , TRX_NU
MBER_DISP , TRX_DATE , TRX_DATE_DISP , BILL_TO_CUSTOMER_ID , BIL
L_TO_CUSTOMER_NAME , SHIP_DATE_ACTUAL_DISP , SHIP_TO_NAME , SHIP
_TO_ADDRESS1 , SHIP_TO_ADDRESS2 , SHIP_TO_ADDRESS3 , SHIP_TO_ADD

     46,298,646        3,452       13,412.1   17.5   828.53    834.22 3761220362
Module: JDBC Thin Client
SELECT DELV_ADDR.ADDRESS1 FROM APPS.OE_ORDER_HEADERS_ALL OE_HEAD
ERS , APPS.RA_SITE_USES_ALL DELV_SITE , APPS.RA_ADDRESSES_ALL DE
LV_ADDR WHERE TO_CHAR(ORDER_NUMBER) = :B1 AND DELV_SITE.SITE_USE
_ID(+) = OE_HEADERS.DELIVER_TO_ORG_ID AND DELV_ADDR.ADDRESS_ID(+
) = DELV_SITE.ADDRESS_ID

     46,298,632        3,440       13,458.9   17.5   814.25    835.98 4273350236
Module: JDBC Thin Client
SELECT DELV_ADDR.ADDRESS2 FROM APPS.OE_ORDER_HEADERS_ALL OE_HEAD
ERS , APPS.RA_SITE_USES_ALL DELV_SITE , APPS.RA_ADDRESSES_ALL DE
LV_ADDR WHERE TO_CHAR(ORDER_NUMBER) = :B1 AND DELV_SITE.SITE_USE
_ID(+) = OE_HEADERS.DELIVER_TO_ORG_ID AND DELV_ADDR.ADDRESS_ID(+
) = DELV_SITE.ADDRESS_ID

     46,271,968        3,452       13,404.4   17.4   815.70    835.14  803969757
Module: JDBC Thin Client
SELECT COALESCE(DELV_ADDR.CITY, DELV_ADDR.PROVINCE) FROM APPS.OE
_ORDER_HEADERS_ALL OE_HEADERS , APPS.RA_SITE_USES_ALL DELV_SITE
, APPS.RA_ADDRESSES_ALL DELV_ADDR WHERE TO_CHAR(ORDER_NUMBER) =
:B1 AND DELV_SITE.SITE_USE_ID(+) = OE_HEADERS.DELIVER_TO_ORG_ID
AND DELV_ADDR.ADDRESS_ID(+) = DELV_SITE.ADDRESS_ID

     40,281,049        3,008       13,391.3   15.2   867.23    857.26 3960143944
Module: EXCEL.EXE
SELECT CASE WHEN ORDER_CATEGORY_CODE = 'MIXED' THEN TO_CHAR(ORDE
R_NUMBER) WHEN ORDER_CATEGORY_CODE = 'RETURN' THEN TO_CHAR(CUST_
PO_NUMBER) END REFERENCE_NUMBER FROM APPS.OE_ORDER_HEADERS_ALL W
HERE TO_CHAR(ORDER_NUMBER) = :B1

     23,112,200            1   23,112,200.0    8.7   412.43    416.11 2208319477
Module: JDBC Thin Client
select  TRANSACTION_BRANCH , BRANCH_ADDRESS_1 , BRANCH_ADDRESS_2
 , BRANCH_PHONES , BRANCH_FAX , BRANCH_TIN , TRX_NUMBER , TRX_NU
MBER_DISP , TRX_DATE , TRX_DATE_DISP , BILL_TO_CUSTOMER_ID , BIL
L_TO_CUSTOMER_NAME , SHIP_DATE_ACTUAL_DISP , SHIP_TO_NAME , SHIP
_TO_ADDRESS1 , SHIP_TO_ADDRESS2 , SHIP_TO_ADDRESS3 , SHIP_TO_ADD

      6,719,590            2    3,359,795.0    2.5    12.82    332.71 2258492566
Module: Scheduler.vshost.exe
select  om_trx.header_id header_id ,       om_trx.order_number o
^LSQL ordered by Gets for DB: OAPROD  Instance: OAPROD  Snaps: 781 -782
-> End Buffer Gets Threshold:     10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
Bad performance statspack report
STATSPACK report for

DB Name         DB Id    Instance     Inst Num Release     Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
OAPROD        4204192100 OAPROD              1 9.2.0.6.0   NO      oel5.unitrad
                                                                   e.local

              Snap Id     Snap Time      Sessions Curs/Sess Comment
            --------- ------------------ -------- --------- -------------------
Begin Snap:       848 08-Jan-13 14:00:15      191      58.0
  End Snap:       849 08-Jan-13 14:30:16      189      53.5
   Elapsed:               30.02 (mins)

Cache Sizes (end)
~~~~~~~~~~~~~~~~~
               Buffer Cache:       288M      Std Block Size:          8K
           Shared Pool Size:       288M          Log Buffer:     10,240K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:             15,339.00             18,115.11
              Logical reads:             48,006.97             56,695.45
              Block changes:                129.73                153.21
             Physical reads:             21,322.15             25,181.11
            Physical writes:                453.54                535.63
                 User calls:                105.47                124.56
                     Parses:                 51.61                 60.95
                Hard parses:                  0.35                  0.41
                      Sorts:                152.73                180.37
                     Logons:                  0.09                  0.10
                   Executes:                280.08                330.77
               Transactions:                  0.85

  % Blocks changed per Read:    0.27    Recursive Call %:     82.69
 Rollback per transaction %:    7.28       Rows per Sort:    642.74

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.78       Redo NoWait %:    100.00
            Buffer  Hit   %:   56.53    In-memory Sort %:    100.00
            Library Hit   %:   99.88        Soft Parse %:     99.32
         Execute to Parse %:   81.57         Latch Hit %:     99.96
Parse CPU to Parse Elapsd %:    1.83     % Non-Parse CPU:     99.35

 Shared Pool Statistics        Begin   End
                               ------  ------
             Memory Usage %:   93.02   92.88
    % SQL with executions>1:   91.97   86.95
  % Memory for SQL w/exec>1:   87.44   82.90

Top 5 Timed Events
~~~~~~~~~~~~~~~~~~                                                     % Total
Event                                               Waits    Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
db file sequential read                         4,716,349      11,481    63.42
buffer busy waits                                 191,973       3,879    21.43
db file scattered read                          8,123,555       1,824    10.07
CPU time                                                          422     2.33
log file parallel write                             1,755         238     1.32
          -------------------------------------------------------------
^LWait Events for DB: OAPROD  Instance: OAPROD  Snaps: 848 -849
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file sequential read         4,716,349          0     11,481      2  3,092.7
buffer busy waits                 191,973         11      3,879     20    125.9
db file scattered read          8,123,555          0      1,824      0  5,326.9
log file parallel write             1,755          0        238    136      1.2
log file sync                       1,208          2        174    144      0.8
control file parallel write           586          0         62    106      0.4
db file parallel read                  36          0         17    479      0.0
latch free                          1,111        723          5      5      0.7
SQL*Net break/reset to clien        4,298          0          0      0      2.8
enqueue                                 3          0          0     83      0.0
SQL*Net more data to client        18,913          0          0      0     12.4
direct path write                  66,717          0          0      0     43.7
control file sequential read          370          0          0      0      0.2
process startup                        12          0          0     11      0.0
direct path read                   72,482          0          0      0     47.5
direct path write (lob)                 1          0          0      9      0.0
db file parallel write                858          0          0      0      0.6
db file single write                    1          0          0      1      0.0
LGWR wait for redo copy                10          0          0      0      0.0
direct path read (lob)                  9          0          0      0      0.0
async disk IO                           1          0          0      0      0.0
SQL*Net message from client       194,370          0    158,285    814    127.5
queue messages                        924        924      7,023   7600      0.6
pipe get                            1,328      1,322      5,267   3966      0.9
wakeup time manager                    60         60      1,678  27967      0.0
jobq slave wait                       238        238        697   2931      0.2
SQL*Net more data from clien       39,093          0          1      0     25.6
SQL*Net message to client         194,377          0          0      0    127.5
          -------------------------------------------------------------
^LBackground Wait Events for DB: OAPROD  Instance: OAPROD  Snaps: 848 -849
-> ordered by wait time desc, waits desc (idle events last)

                                                                   Avg
                                                     Total Wait   wait    Waits
Event                               Waits   Timeouts   Time (s)   (ms)     /txn
---------------------------- ------------ ---------- ---------- ------ --------
log file parallel write             1,755          0        238    136      1.2
db file scattered read              1,470          0         83     56      1.0
control file parallel write           584          0         61    105      0.4
db file sequential read               786          0         44     56      0.5
control file sequential read          253          0          0      0      0.2
latch free                              7          2          0      2      0.0
db file parallel write                858          0          0      0      0.6
rdbms ipc reply                        10          0          0      0      0.0
LGWR wait for redo copy                10          0          0      0      0.0
direct path read                       47          0          0      0      0.0
buffer busy waits                       2          0          0      0      0.0
direct path write                      47          0          0      0      0.0
rdbms ipc message                   9,487      2,212      6,577    693      6.2
pmon timer                            604        604      1,755   2906      0.4
smon timer                            144          0      1,618  11238      0.1
          -------------------------------------------------------------
^LSQL ordered by Gets for DB: OAPROD  Instance: OAPROD  Snaps: 848 -849
-> End Buffer Gets Threshold:     10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
   total % to exceed 100

                                                     CPU      Elapsd
  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
     53,507,965        3,993       13,400.4   61.9  1198.56   1248.98 3960143944
Module: EXCEL.EXE
SELECT CASE WHEN ORDER_CATEGORY_CODE = 'MIXED' THEN TO_CHAR(ORDE
R_NUMBER) WHEN ORDER_CATEGORY_CODE = 'RETURN' THEN TO_CHAR(CUST_
PO_NUMBER) END REFERENCE_NUMBER FROM APPS.OE_ORDER_HEADERS_ALL W
HERE TO_CHAR(ORDER_NUMBER) = :B1

     11,925,524            1   11,925,524.0   13.8   144.55   3413.42 2663139152
Module: EXCEL.EXE
SELECT VW_USR_SL_CUSTOMER_PERFORMANCE.HEADER_ID, VW_USR_SL_CUSTO
MER_PERFORMANCE.ORDER_NUMBER, VW_USR_SL_CUSTOMER_PERFORMANCE.CUS
TOMER_PO_NUMBER, VW_USR_SL_CUSTOMER_PERFORMANCE.AR_TRX_NUMBER, V
W_USR_SL_CUSTOMER_PERFORMANCE.ORDERED_DATE, VW_USR_SL_CUSTOMER_P
ERFORMANCE.PERPOST, VW_USR_SL_CUSTOMER_PERFORMANCE.SALES_PERIOD,

      9,884,668      214,884           46.0   11.4    66.35     82.39 2827770190
Module: oracle@misdata.unitrade.local (TNS V1-V3)
SELECT CHAIN_ID FROM JSCUS.USR_SL_SOLOMON_LKUP_CUST_REF@OAPROD W
HERE SOLOMON_CUST_ID = :B1 GROUP BY CHAIN_ID

      6,023,418            6    1,003,903.0    7.0     9.83    198.32 2076298416
Module: FNDWFBG
BEGIN WF_ENGINE.BACKGROUNDCONCURRENT( :errbuf, :rc,:A0,:A1,:A2,:
A3,:A4,:A5); END;

      5,793,148            6      965,524.7    6.7     7.04    101.65 2881611387
Module: FNDWFBG
SELECT /*+ ORDERED USE_NL (WIASP WI WPAP WAP)                 IN
DEX (WIASP WF_ITEM_ACTIVITY_STATUSES_N1) */ WIASP.ROWID ROW_ID F
ROM WF_ITEM_ACTIVITY_STATUSES WIASP, WF_ITEMS WI, WF_PROCESS_ACT
IVITIES WPAP, WF_ACTIVITIES WAP WHERE WIASP.PROCESS_ACTIVITY = W
PAP.INSTANCE_ID AND WPAP.ACTIVITY_ITEM_TYPE = WAP.ITEM_TYPE AND

      4,397,623            4    1,099,405.8    5.1    15.56    840.30 3547482375
Module: JDBC Thin Client
SELECT * FROM JSCUS.VW_USR_AP_VOUCHER_UNACCOUNTED WHERE REFERENC
E_NUMBER BETWEEN :1 AND COALESCE(:2,:3) AND ORG_ID = :4 ORDER BY
 INVOICE_ID , NATURAL_ACCOUNT

      2,349,056            1    2,349,056.0    2.7     5.38     54.28 3437302100
Module: APXIWALL
SELECT ROW_ID,INVOICE_ID,VENDOR_ID,VENDOR_SITE_ID,SET_OF_BOOKS_I
D,VENDOR_NAME,VENDOR_SITE_CODE,VENDOR_NUMBER,NUM_1099,INVOICE_NU
M,INVOICE_TYPE,INVOICE_DATE,BATCH_NAME,INVOICE_TYPE_LOOKUP_CODE,
INVOICE_CURRENCY_CODE,PAYMENT_CURRENCY_CODE,ACTUAL_INVOICE_AMOUN
T,INVOICE_AMOUNT,ORIGINAL_PREPAYMENT_AMOUNT,VOUCHER_NUM,DOC_SEQU

      2,001,035            1    2,001,035.0    2.3     7.40     46.65  824154294
Module: JDBC Thin Client
SELECT *^M FROM JSCUS.VW_USR_AP_VOUCHER_ACCTG^M WHERE VOUCHER_NUMB
^LSQL ordered by Gets for DB: OAPROD  Instance: OAPROD  Snaps: 848 -849
-> End Buffer Gets Threshold:     10000
-> Note that resources reported for PL/SQL includes the resources used by
   all SQL statements called within the PL/SQL code.  As individual SQL
   statements are also reported, it is possible and valid for the summed
Edited by: yxes2013 on 8.1.2013 8:45
  • 1. Re: Performance Issue
    Rob_J Journeyer
    Currently Being Moderated
    I can't see those reports because the it's blocked at my work :(

    Care the post the top timed events sections and important bits?

    Also, didn't you ask a question the other day about this same subject? Where there were many recommendations, such as increasing REDO logs and tuning some of the SQL? Was that resolved?
  • 2. Re: Performance Issue
    Aman.... Oracle ACE
    Currently Being Moderated
    I am on my phone so can't download and read the reports but from this,
    But then again after the database was restarted and the user started to run their process again it still very slow.
    It seems that you have undersized your memory parameters or you have an application which is somehow consuming the entire memory areas of yours and finally, when there is a memory crunch , system seems to be crawling. That's just a guess though as I haven't seen the report.

    Aman....
  • 3. Re: Performance Issue
    Rob_J Journeyer
    Currently Being Moderated
    This is the same DB we were looking at in the previous post, right?

    1. Did you change the REDO log size?
    2. Did you look at the SQL Jonathan Lewis pointed out?

    The report shows that you are OK on CPU for that time period.
    The next biggest wait is db file scattered reads, so most likely full table scans from your queries
    Your db_cache is tiny, 288MB, how much data are you selecting? If more than 288MB, can you increase your cache?
    You'll then need to look at the SQL statements in order of time taken/resources used and try to optimize them if you can

    And your bad performance time shows that the db file sequenital reads are the bottleneck, along with buffer busy waits. I'd say this is because your queries are waiting for one another to read the blocks from disk into your buffer cache because it's too small to hold enough data and has to keep swapping them in and out of the cache.

    My answer would be to first increase db_cache_size in order to alleviate the problems if it's causing you such an issue, then look at the SQL queries which are running and try to improve them. 288MB is incredibly small for a database. What kind of data volumes are you working with?

    Edited by: Rob_J on Jan 8, 2013 4:56 PM
  • 4. Re: Performance Issue
    yxes2013 Newbie
    Currently Being Moderated
    Thanks,
    It seems that you have undersized your memory parameters or you have an application which is somehow consuming the entire memory areas of yours and finally, when there is a memory crunch , system seems to be crawling. That's just a guess though as I haven't seen the report.
    But why is it okay yesterday? The user is processing same number of transaction. or maybe they are not telling the truth or maybe there are hidden jobs being activated? But the operators
    said they just run same thing.
  • 5. Re: Performance Issue
    Rob_J Journeyer
    Currently Being Moderated
    Look at the queries in the report, they are different. One day, good day, they are all from JDBC clients. Bad day they are from EXCEL.exe.
  • 6. Re: Performance Issue
    jgarry Guru
    Currently Being Moderated
    [url http://tkyte.blogspot.com/2012/05/another-debugging-story.html]Was it raining on Monday?
  • 7. Re: Performance Issue
    sb92075 Guru
    Currently Being Moderated
    yxes2013 wrote:
    Thanks,
    It seems that you have undersized your memory parameters or you have an application which is somehow consuming the entire memory areas of yours and finally, when there is a memory crunch , system seems to be crawling. That's just a guess though as I haven't seen the report.
    But why is it okay yesterday? The user is processing same number of transaction. or maybe they are not telling the truth or maybe there are hidden jobs being activated? But the operators
    said they just run same thing.
    since you decide to not answer any of our questions, we can decide to not answer any of your questions!
  • 8. Re: Performance Issue
    yxes2013 Newbie
    Currently Being Moderated
    Thanks,

    Yes this is the same issue last Jan 2. Its happening internittently.

    I already increased the redo to 100Mb and the undo_retention from 1800 to 3600 but I still get ORA-01555

    The logswitching seem not to fast now:
    Thread 1 opened at log sequence 136562
      Current log# 3 seq# 136562 mem# 0: /u02/oracle/oaproddata/log03a.dbf
      Current log# 3 seq# 136562 mem# 1: /u02/oracle/oaproddata/log03b.dbf
    Successful open of redo thread 1
    Tue Jan  8 11:59:23 2013
    MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
    Tue Jan  8 11:59:23 2013
    SMON: enabling cache recovery
    Tue Jan  8 11:59:23 2013
    Successfully onlined Undo Tablespace 368.
    Tue Jan  8 11:59:23 2013
    SMON: enabling tx recovery
    Tue Jan  8 11:59:23 2013
    Database Characterset is UTF8
    replication_dependency_tracking turned off (no async multimaster replication found)
    Completed: ALTER DATABASE OPEN
    Tue Jan  8 12:02:18 2013
    Beginning log switch checkpoint up to RBA [0x21573.2.10], SCN: 0x056e.7521cc0e
    Thread 1 advanced to log sequence 136563
      Current log# 4 seq# 136563 mem# 0: /u02/oracle/oaproddata/log04a.dbf
      Current log# 4 seq# 136563 mem# 1: /u02/oracle/oaproddata/log04b.dbf
    Tue Jan  8 12:22:33 2013
    Completed checkpoint up to RBA [0x21573.2.10], SCN: 0x056e.7521cc0e
    Tue Jan  8 12:50:04 2013
    Beginning log switch checkpoint up to RBA [0x21574.2.10], SCN: 0x056e.752326a7
    Thread 1 advanced to log sequence 136564
      Current log# 3 seq# 136564 mem# 0: /u02/oracle/oaproddata/log03a.dbf
      Current log# 3 seq# 136564 mem# 1: /u02/oracle/oaproddata/log03b.dbf
    Tue Jan  8 13:10:19 2013
    Completed checkpoint up to RBA [0x21574.2.10], SCN: 0x056e.752326a7
    Tue Jan  8 13:49:16 2013
    Beginning log switch checkpoint up to RBA [0x21575.2.10], SCN: 0x056e.7524a192
    Thread 1 advanced to log sequence 136565
      Current log# 4 seq# 136565 mem# 0: /u02/oracle/oaproddata/log04a.dbf
      Current log# 4 seq# 136565 mem# 1: /u02/oracle/oaproddata/log04b.dbf
    Tue Jan  8 14:10:16 2013
    Completed checkpoint up to RBA [0x21575.2.10], SCN: 0x056e.7524a192
    Tue Jan  8 14:58:52 2013
    Errors in file /u02/oracle/oaproddb/9.2.0/admin/OAPROD_oel5/udump/oaprod_ora_8774.trc:
    ORA-12570: TNS:packet reader failure
    ORA-06512: at "JSCUS.FUNC_GET_MTL_SRC", line 23
    Tue Jan  8 15:03:27 2013
    Beginning log switch checkpoint up to RBA [0x21576.2.10], SCN: 0x056e.7527328b
    Thread 1 advanced to log sequence 136566
      Current log# 3 seq# 136566 mem# 0: /u02/oracle/oaproddata/log03a.dbf
      Current log# 3 seq# 136566 mem# 1: /u02/oracle/oaproddata/log03b.dbf
    Tue Jan  8 15:23:42 2013
    Completed checkpoint up to RBA [0x21576.2.10], SCN: 0x056e.7527328b
    Tue Jan  8 15:42:24 2013
    I mean I got tns packet failer at the time when the problem hits at 2pm
    and also ORA-01555

    ORA-12570: TNS:packet reader failure
    ORA-06512: at "JSCUS.FUNC_GET_MTL_SRC", line 23
    Tue Jan 8 15:03:27 2013
    Beginning log switch checkpoint up to RBA [0x21576.2.10], SCN: 0x056e.7527328b


    Then after we restarted the server and database after 1 hours Ora-01555 occurs again but no more tns packet error.

    Edited by: yxes2013 on 8.1.2013 9:24
  • 9. Re: Performance Issue
    sb92075 Guru
    Currently Being Moderated
    [oracle@localhost dbs]$ oerr ora 12570
    12570, 00000, "TNS:packet reader failure"
    // *Cause: An error occurred during a data receive.
    // *Action: Not normally visible to the user. For further details, turn
    // on tracing and reexecute the operation. If error persists, contact
    // Oracle Customer Support.
  • 10. Re: Performance Issue
    Aman.... Oracle ACE
    Currently Being Moderated
    100mb size for a production db is actually a little small. How about you set it to something really large, for example like 1gb and along with set the parameter archive_lag_target to control the log switching?

    Aman....
  • 11. Re: Performance Issue
    Rob_J Journeyer
    Currently Being Moderated
    We were looking at a different time period, though. Your issue previously was from 22:00 to 00:00. How is the log switching then?

    What did you base the 1800 to 3600 decision on? You need to look at how long your longest running query is, in seconds, and set the undo to at least that value. How long is the query which runs running for before you get the ORA-01555 error?

    Also take note of what process is receiving the error, as sb pointed out before if I remember correctly it can also be caused by committing inside of a pl/sql loop

    Your second issue is related to poor performance of SQL queries, so answer the following questions:

    1. Are the queries optimal?
    2. If so, how much data are they dealing with? KBs, MBs, GBs?
    3. Can you increase your SGA to handle more appropriately the volume required by the queries?
    4. Also note that the queries in your good and bay days are different so the load pattern is not comparable
  • 12. Re: Performance Issue
    Jonathan Lewis Oracle ACE Director
    Currently Being Moderated
    yxes2013 wrote:

    This is the statspack report yesterday from 2pm-3pm where the performance is good. And the next is the statspack report today from 2pm-2:30pm where the performance problem occurs.
    Please help me find the difference or the problem on the 2nd statspack. Your help is very much appreciated. Thanks a lot.

    http://www.datafilehost.com/download-49750b9f.html (normal performance)
    http://www.datafilehost.com/download-f6c8ebbe.html (bad performance)
    Top 5 Timed Events
    ~~~~~~~~~~~~~~~~~~                                                     % Total
    Event                                               Waits    Time (s) Ela Time
    -------------------------------------------- ------------ ----------- --------
    CPU time                                                        5,152    71.73
    
    Event                               Waits   Timeouts   Time (s)   (ms)     /txn
    ---------------------------- ------------ ---------- ---------- ------ --------
    db file scattered read         24,697,470          0      1,152      0  8,469.6
    db file sequential read        12,905,526          0        733      0  4,425.8
    log file parallel write             3,682          0         48     13      1.3
    buffer busy waits               1,375,553          0         46      0    471.7
    log file sync                       2,109          0         35     17      0.7
    
    
    Event                                               Waits    Time (s) Ela Time
    -------------------------------------------- ------------ ----------- --------
    CPU time                                                          422     2.33
    Avg
    Total Wait wait Waits
    Event Waits Timeouts Time (s) (ms) /txn
    ---------------------------- ------------ ---------- ---------- ------ --------
    db file sequential read 4,716,349 0 11,481 2 3,092.7
    buffer busy waits 191,973 11 3,879 20 125.9
    db file scattered read 8,123,555 0 1,824 0 5,326.9
    log file parallel write 1,755 0 238 136 1.2
    log file sync 1,208 2 174 144 0.8

    Counterintuitively you say that your performance is good in the first case where the machine is doing a ludicrous amount of extremely inefficient work. This is an indication that your machine is massively overpowered and you could possibly save a fortune on Oracle licences.

    When performance is bad, the machine is doing much less work - which means that something is introducing contention which stops your (inefficient) processes from being able to work. One question worth asking is, are there other things on the machine outside oracle which suddenly steal the filesystem cache and leave a large number of your "physical reads" actually going to disc rather than coming from memory ?

    The other check is simply to find something that gets bigger when the performance gets worse. The only thing I can see on a quick glance through the reports is the number of direct path writes (which report as physical writes - for a total of about 800,000 blocks written. These writes may be enough to interfere with your extravagent rate of reads.

    Since the redo size DROPs, these writes may be to the temporary tablespace (sprt/hash) or they may be the result of NOLOGGING operations such as direct path loads or table moves or index rebuilds. When you look at the tablespace I/O stats, they look like workarea operations - so you may be able to find the driving SQL in v$sql_workarea.

    (If you got rid of the half dozen massively inefficient SQL statements it's possible that whatever causes the slow-down wouldn't have anything that could be slowed down, though.

    Regards
    Jonathan Lewis
  • 13. Re: Performance Issue
    yxes2013 Newbie
    Currently Being Moderated
    I thank you all,


    1. Are the queries optimal?
    I dont know :( do I need to show you the explain plan. How do I know if its optimal?
    2. If so, how much data are they dealing with? KBs, MBs, GBs?
    They said if just around 200 invoices. Compared to others I see in metalink that logs issue whiich has 10,000 PO's invioces.
    3. Can you increase your SGA to handle more appropriately the volume required by the queries?
    Is it already 1.7 which is the limit of 32 bit Oracle. which we have.
    4. Also note that the queries in your good and bay days are different so the load pattern is not comparable.
    It maybe that that queries has finished fast and they have done other programs being caught in that time range. Do I need generate statspack starting 8am to 5pm? so that everything is captured?
    5. What did you base the 1800 to 3600 decision on? You need to look at how long your longest running query is, in seconds, and set the undo to at least that value. How long is the query which runs running for before you get the ORA-01555 error?
    The logical thing is just to test it by increasing, but it seems does not matter as "sbt" has mentioned.
    6. Your db_cache is tiny, 288MB, how much data are you selecting? If more than 288MB, can you increase your cache?

    How do I increase my cache size?

    Edited by: yxes2013 on 8.1.2013 15:45
  • 14. Re: Performance Issue
    yxes2013 Newbie
    Currently Being Moderated
    Was it raining on Monday?
    No rains here only sometime dizzles. Or is this a joke?
1 2 3 4 Previous Next

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points