A post by Jonathan Lewis inspired me to finally complete my version of the Oracle session performance snapper script, which main characteristics are
- it reports Oracle session level performance counter and wait information in real time
- it does NOT require any database objects to be created
If you are a DBA or consultant working on ad-hoc performance issues, you will like it!
Are you familiar with following situation?
(Monday morning)
Customer: Hey, we need your help! We have serious performance issues in our production environment. It’s a database with x000 online users, several parallel data feeds, continuous batch jobs and reporting going on.
Users have started experiencing occasional bad performance and some batch jobs as well.
You: Ok, lets see it. Do you have any performance monitoring tools installed?
Customer: Yes, we have Xxxxx Xxxxxxxxx installed which shows us a nice green or red light on big screen depending whether there are any problems or not.
You: What color is it showing now?
Customer: Green
You: But you still have the performance problem you described earlier?
Customer: Yes
You: Do you have ANY performance monitoring tools installed?
Customer: Well, we also have a statspack snapshot taken every morning and evening to capture the business workload.
You: Um… Ok… you know forget about it. Can I create a small package to capture some useful performance info on the problematic sessions?
Customer: Yes, but we need to put the DDL scripts through the change review board which gathers every Thursday… but we can’t wait that long!
You: Can we enable tracing?
Customer: Enabling tracing is a change and all changes must go through review board. Also, we don’t really know which exact sessions are affected, it just happens for seemingly random ones… and we can’t just trace every session, can we?
You: Ok, give me a sqlplus window and Excel, we’ll figure something out.
…And now follows a tedious manual SQL execution and copy & paste exercise from various V$ views for getting some meaningful performance information out of Oracle.
Well, not anymore, because The Oracle Session Snapper is in town!
If you know vmstat for Unix, you know it reports you various system level statistic counter deltas over a period you choose.
Well, the Oracle Session Snapper output looks somewhat similar, but it reports you session level deltas of Oracle v$sesstat counters, wait events and starting from 10g also session time model statistics.
All info can be reported in real time, without a need for running and timing multiple SQL scripts and manual calculation of deltas.
And the key unique point of the Session Snapper is – it does not require creation of any database objects, thus no changes in the database at all! Everything is done from within a sqlplus script or anonymous PL/SQL block.
This means that you will be able to get quick session-level performance snapshots even in heavily change-controlled environments, where no object creation whatsoever is allowed without going through a long process.
You can read all the usage details from the script header, but here’s one example of its output:
Tanel@Sol01> @snapper out 1 3 475
-- Session Snapper v1.03 by Tanel Poder ( http://www.tanelpoder.com )
--------------------------------------------------------------------------------------------------------------------------------------------
-- SID, SNAPSHOT START , SECONDS , TYPE, STATISTIC , DELTA, D/SEC, HDELTA, HD/SEC
--------------------------------------------------------------------------------------------------------------------------------------------
DATA, 475, 20070820 01:17:47, 1, STAT, session logical reads , 88232, 88232, 88.23k 88.23k
DATA, 475, 20070820 01:17:47, 1, STAT, consistent gets , 88233, 88233, 88.23k 88.23k
DATA, 475, 20070820 01:17:47, 1, STAT, consistent gets from cache , 88232, 88232, 88.23k 88.23k
DATA, 475, 20070820 01:17:47, 1, STAT, calls to get snapshot scn: kcmgss , 556, 556, 556 556
DATA, 475, 20070820 01:17:47, 1, STAT, no work - consistent read gets , 87677, 87677, 87.68k 87.68k
DATA, 475, 20070820 01:17:47, 1, STAT, table scans (short tables) , 139, 139, 139 139
DATA, 475, 20070820 01:17:47, 1, STAT, table scan rows gotten , 7429598, 7429598, 7.43M 7.43M
DATA, 475, 20070820 01:17:47, 1, STAT, table scan blocks gotten , 87676, 87676, 87.68k 87.68k
DATA, 475, 20070820 01:17:47, 1, STAT, buffer is pinned count , 138, 138, 138 138
-- End of snap 1
DATA, 475, 20070820 01:17:48, 1, STAT, session logical reads , 87779, 87779, 87.78k 87.78k
DATA, 475, 20070820 01:17:48, 1, STAT, consistent gets , 87772, 87772, 87.77k 87.77k
DATA, 475, 20070820 01:17:48, 1, STAT, consistent gets from cache , 87772, 87772, 87.77k 87.77k
DATA, 475, 20070820 01:17:48, 1, STAT, calls to get snapshot scn: kcmgss , 552, 552, 552 552
DATA, 475, 20070820 01:17:48, 1, STAT, no work - consistent read gets , 87210, 87210, 87.21k 87.21k
DATA, 475, 20070820 01:17:48, 1, STAT, table scans (short tables) , 138, 138, 138 138
DATA, 475, 20070820 01:17:48, 1, STAT, table scan rows gotten , 7389897, 7389897, 7.39M 7.39M
DATA, 475, 20070820 01:17:48, 1, STAT, table scan blocks gotten , 87211, 87211, 87.21k 87.21k
DATA, 475, 20070820 01:17:48, 1, STAT, buffer is pinned count , 136, 136, 136 136
-- End of snap 2
DATA, 475, 20070820 01:17:49, 1, STAT, session logical reads , 87580, 87580, 87.58k 87.58k
DATA, 475, 20070820 01:17:49, 1, STAT, consistent gets , 87587, 87587, 87.59k 87.59k
DATA, 475, 20070820 01:17:49, 1, STAT, consistent gets from cache , 87587, 87587, 87.59k 87.59k
DATA, 475, 20070820 01:17:49, 1, STAT, calls to get snapshot scn: kcmgss , 552, 552, 552 552
DATA, 475, 20070820 01:17:49, 1, STAT, no work - consistent read gets , 87046, 87046, 87.05k 87.05k
DATA, 475, 20070820 01:17:49, 1, STAT, table scans (short tables) , 138, 138, 138 138
DATA, 475, 20070820 01:17:49, 1, STAT, table scan rows gotten , 7375781, 7375781, 7.38M 7.38M
DATA, 475, 20070820 01:17:49, 1, STAT, table scan blocks gotten , 87041, 87041, 87.04k 87.04k
DATA, 475, 20070820 01:17:49, 1, STAT, buffer is pinned count , 137, 137, 137 137
-- End of snap 3
PL/SQL procedure successfully completed.
The output contains 3 x 1 second snapshot of session 475 doing heavy nested looping. Note that even though the CPU time used was not updated, the logical IO counts for that session had still increased.
So this tool can be very valuable diagnosing what’s going on when the session seems to be 100% on CPU doing something.
Read more…
Tanel Poder Administration, Cool stuff, Oracle, Performance, Tools
Recent Comments