Gwen Shapira has written an article about a good example of a non-trivial performance problem.

I’m not talking about anything advanced here (such as bugs or problems arising at OS/Oracle touchpoint) but that sometimes the root cause of a problem (or at least the reason why you notice this problem now) is not something deeply technical or related to some specific SQL optimizer feature or a configuration issue. Instead of focusing on the first symptom you see immediately, it pays off to take a step back and see how the problem task/application/SQL is actually used by the users or client applications.

In other words, talk to the users, ask how exactly they experience the problem and then drill down from there.

Tanel Poder Administration, Oracle, Performance, Troubleshooting, Tuning Oracle, Performance, SQL, Troubleshooting, Tuning

Some time ago I wrote an article about the 10g+ SQL_ID being just a hash value of the SQL statement text. It’s just like the “old” SQL_HASH_VALUE, only twice longer (8 last bytes instead of 4 last bytes of the MD5 hash value of SQL text).

Slavik Markovich has written a nice python script for calculating SQL_IDs and SQL hash values from SQL text using that approach.

Slavik’s article is available here:

http://www.slaviks-blog.com/2010/03/30/oracle-sql_id-and-hash-value/

Tanel Poder Cool stuff, Internals, Oracle, Security Internals, Oracle

I wrote a latch contention troubleshooting article for IOUG Select journal last year (it was published earlier this year). I have uploaded this to tech.E2SN too, I recommend you to read it if you want to become systematic about latch contention troubleshooting:

http://tech.e2sn.com/oracle/troubleshooting

I’m working on getting the commenting & feedback work at tech.E2SN site too, but for now you can comment here at this blog entry…

Tanel Poder Cool stuff, Internals, Oracle, Performance, Tools, Troubleshooting, Tuning contention, latch, method, Oracle, Performance, scripts, systematic, Tools, Troubleshooting, Tuning

This is an updated version of Snapper, which works ok on Oracle 10.1 now as well (9i support is coming some time in the future :)

Thanks to Jamey Johnston for sending me the fix info (and saving me some time that way :)

So if you have some problems with Snapper on Oracle 10.1, please make sure you have the latest version v3.11, which you can get from here:

http://tech.e2sn.com/oracle-scripts-and-tools/session-snapper

The output below is from Snapper 3.11 on Oracle 10.1.0.5, the ASH columns in the bottom part of the output are displayed correctly now:

SQL> @snapper ash,ash1,ash2,ash3,stats,gather=t 15 1 all
Sampling with interval 15 seconds, 1 times...

-- Session Snapper v3.11 by Tanel Poder @ E2SN ( http://tech.e2sn.com )

----------------------------------------------------------------------------------------------------------------------
    SID, USERNAME  , TYPE, STATISTIC                               ,         DELTA, HDELTA/SEC,    %TIME, GRAPH
----------------------------------------------------------------------------------------------------------------------
     52, SYSTEM    , TIME, PL/SQL execution elapsed time           ,         53968,      3.6ms,      .4%, |          |
     52, SYSTEM    , TIME, DB CPU                                  ,         10000,   666.67us,      .1%, |          |
     52, SYSTEM    , TIME, sql execute elapsed time                ,        118225,     7.88ms,      .8%, |@         |
     52, SYSTEM    , TIME, DB time                                 ,        118632,     7.91ms,      .8%, |@         |
     54, SYSTEM    , TIME, hard parse elapsed time                 ,        289905,    19.33ms,     1.9%, |@         |
     54, SYSTEM    , TIME, parse time elapsed                      ,        528034,     35.2ms,     3.5%, |@         |
     54, SYSTEM    , TIME, PL/SQL execution elapsed time           ,       5010579,   334.04ms,    33.4%, |@@@@      |
     54, SYSTEM    , TIME, DB CPU                                  ,      10660000,   710.67ms,    71.1%, |@@@@@@@@  |
     54, SYSTEM    , TIME, sql execute elapsed time                ,      12920952,    861.4ms,    86.1%, |@@@@@@@@@ |
     54, SYSTEM    , TIME, DB time                                 ,      12937606,   862.51ms,    86.3%, |@@@@@@@@@ |
     54, SYSTEM    , TIME, sequence load elapsed time              ,          1079,    71.93us,      .0%, |          |
     56, (MMNL)    , TIME, background cpu time                     ,           940,    62.67us,      .0%, |          |
     56, (MMNL)    , TIME, background elapsed time                 ,           940,    62.67us,      .0%, |          |
     58, (MMON)    , TIME, background cpu time                     ,           158,    10.53us,      .0%, |          |
     58, (MMON)    , TIME, background elapsed time                 ,           158,    10.53us,      .0%, |          |
     64, (RBAL)    , TIME, background cpu time                     ,            86,     5.73us,      .0%, |          |
     64, (RBAL)    , TIME, background elapsed time                 ,            86,     5.73us,      .0%, |          |
     68, (CJQ0)    , TIME, background cpu time                     ,           820,    54.67us,      .0%, |          |
     68, (CJQ0)    , TIME, background elapsed time                 ,           820,    54.67us,      .0%, |          |
     70, (SMON)    , TIME, background cpu time                     ,           141,      9.4us,      .0%, |          |
     70, (SMON)    , TIME, background elapsed time                 ,           141,      9.4us,      .0%, |          |
     71, (CKPT)    , TIME, background cpu time                     ,         14515,   967.67us,      .1%, |          |
     71, (CKPT)    , TIME, background elapsed time                 ,         14515,   967.67us,      .1%, |          |
     72, (LGWR)    , TIME, background cpu time                     ,       1530000,      102ms,    10.2%, |@         |
     72, (LGWR)    , TIME, background elapsed time                 ,       1954778,   130.32ms,    13.0%, |@@        |
     73, (DBW0)    , TIME, background cpu time                     ,         10000,   666.67us,      .1%, |          |
     73, (DBW0)    , TIME, background elapsed time                 ,        268787,    17.92ms,     1.8%, |@         |
     74, (MMAN)    , TIME, background cpu time                     ,           141,      9.4us,      .0%, |          |
     74, (MMAN)    , TIME, background elapsed time                 ,           141,      9.4us,      .0%, |          |
     75, (PMON)    , TIME, background cpu time                     ,          1636,   109.07us,      .0%, |          |
     75, (PMON)    , TIME, background elapsed time                 ,          1636,   109.07us,      .0%, |          |
--  End of Stats snap 1, end=2010-03-27 16:37:13, seconds=15

-----------------------------------------------------------------------
Active% | SQL_ID          | EVENT                     | WAIT_CLASS
-----------------------------------------------------------------------
    61% | 6d0z2j01c8ytc   | ON CPU                    | ON CPU
    22% |                 | log file parallel write   | System I/O
     7% | 6d0z2j01c8ytc   | db file sequential read   | User I/O
     3% | 0zkt25f36kbzd   | ON CPU                    | ON CPU
     3% |                 | db file parallel write    | System I/O
     2% | g1xapjmt4vm5c   | ON CPU                    | ON CPU
     2% |                 | ON CPU                    | ON CPU
     2% | gaxwgwd72b3pn   | ON CPU                    | ON CPU
     1% | 4ftbahd08ab2a   | ON CPU                    | ON CPU
     1% | c69wrxcndxuzw   | ON CPU                    | ON CPU

-----------------------------------------------------
Active% | EVENT                     | WAIT_CLASS
-----------------------------------------------------
    76% | ON CPU                    | ON CPU
    22% | log file parallel write   | System I/O
     9% | db file sequential read   | User I/O
     3% | db file parallel write    | System I/O
     3% | db file scattered read    | User I/O
     1% | direct path write temp    | User I/O

----------------------------------
Active% |    SID | SQL_ID
----------------------------------
    69% |     54 | 6d0z2j01c8ytc
    23% |     72 |
     3% |     54 | 0zkt25f36kbzd
     3% |     73 |
     3% |     54 | 8qs4shjvhk2w4
     2% |     54 | g1xapjmt4vm5c
     2% |     54 | gaxwgwd72b3pn
     1% |     54 | 3w6304ztrww4h
     1% |     54 | b86h705svfmjz
     1% |     54 | drppqann6dwfa

---------------------------------------------------
Active% | PLSQL_OBJE | PLSQL_SUBP | SQL_ID
---------------------------------------------------
    69% | N/A        | N/A        | 6d0z2j01c8ytc
    27% | N/A        | N/A        |
     3% | N/A        | N/A        | 0zkt25f36kbzd
     3% | N/A        | N/A        | 8qs4shjvhk2w4
     2% | N/A        | N/A        | g1xapjmt4vm5c
     2% | N/A        | N/A        | gaxwgwd72b3pn
     1% | N/A        | N/A        | 3w6304ztrww4h
     1% | N/A        | N/A        | b86h705svfmjz
     1% | N/A        | N/A        | drppqann6dwfa
     1% | N/A        | N/A        | c69wrxcndxuzw

--  End of ASH snap 1, end=2010-03-27 16:37:13, seconds=15, samples_taken=96

PL/SQL procedure successfully completed.

SQL>

Tanel Poder Oracle, Tools, Troubleshooting, Tuning Oracle, Performance, scripts, snapper, Tools, Troubleshooting, Tuning