{"id":1505,"date":"2009-07-02T12:00:00","date_gmt":"2009-07-02T12:00:00","guid":{"rendered":"http:\/\/orcldoug.com\/blog\/?p=1505"},"modified":"2009-07-02T12:00:00","modified_gmt":"2009-07-02T12:00:00","slug":"session-level-ash-reports","status":"publish","type":"post","link":"http:\/\/orcldoug.com\/blog\/2009\/07\/02\/session-level-ash-reports\/","title":{"rendered":"Session Level ASH Reports"},"content":{"rendered":"

Some features in this post require a Diagnostics Pack license.<\/em><\/p>\n

I noticed a post on H.Tongu\u00e7 Y\u0131lmaz’s blog<\/a> about filtering ASH data to look at the actions of a specific instrumented query. There are a few strange things that I was going to comment on but the blog requires me to use a WordPress account before I can post. I remember this has stopped me from commenting on a few interesting posts there in the past so I’ve decided to post some comments here and hopefully they’ll appear as a trackback or pingback or some such modern thing 😉<\/p>\n

I think the post is really showing two different things, one more successfully than the other.<\/p>\n

1) Using DBMS_APPLICATION_INFO to instrument code so that we can analyse what it’s doing. It is incredibly useful and Oracle’s tools are all geared up to use the info if it’s there. But that’s not really about ASH as such, because the information would also be written to trace files too and would prove just as useful there. You could use trcsess<\/a> with module or client_id, service, action or module and you would have a consolidated trace file with the same application-aware view of things, without the sampling gaps inherent in ASH data. Of course, you’d need to know about the problem in advance or be able to recreate it.<\/p>\n

2) Filtering ASH data to see what a specific user or application is doing. In this case it’s a parallel query but if I wanted to look at pq activity with ASH, I think I’d want to include the QC_SESSION_ID and possibly QC_INSTANCE_ID to tie things together. I don’t think it’s necessary for what the example’s trying to show, but it’s worth knowing about if you didn’t already.<\/p>\n

However, I have a couple of real problems with the ASH query shown. (Recreated here with some of the white space removed from the results to make it fit the width of this template.)<\/p>\n

SELECT session_id,\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 client_id,\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 event,\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SUM(wait_time + time_waited) total_wait_time\n\u00a0 FROM v$active_session_history\n\u00a0WHERE client_id = 'your_identifier'\n\u00a0\u00a0 AND sample_time BETWEEN SYSDATE - 30 \/ 1440 AND SYSDATE\n\u00a0GROUP BY session_id,\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 client_id,\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 event\n\u00a0ORDER BY 2;\n\nSESSION_ID CLIENT_ID\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 EVENT\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 TOTAL_WAIT_TIME\n---------- ------------------------ ------------------- ---------------\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 223 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 latch free\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3969275\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 292 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 direct path read\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 5304169\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 241 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 direct path read\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1133055\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 273 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 111542310\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 235 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 direct path read\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1052545\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 235 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 latch free\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3969283\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 223 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 direct path read\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 1003455\n\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 241 your_identifier\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 latch free\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 3969486\n\n8 rows selected\n<\/pre>\n
I’ll summarise what I think this query is meant to be returning as ‘All activity for a given client id in the last 30 minutes, showing the total time waited for each event by each session used’. <\/p>\n
I see more problems every time I look at this, but a few off the top of my head …<\/p>\n
1) Probably the most important is the SUM(wait_time + time_waited) as a measure of total wait time. It’s not total wait time. First, ASH is sampled data so it doesn’t contain all of the events. SUM-ing the data might give the illusion of something useful, but we have no idea what happened within the one second sample points! That’s why the Top Sessions section of the Oracle-supplied ASH report doesn’t report the amount of time spent on various events, but the percentage of samples over the period. Here’s an example from one of my course slides.<\/p>\n
\"\"<\/p>\n
Second, why WAIT_TIME + TIME_WAITED?<\/p>\n
2) There’s no filtering on session_state so it’s not obvious that the group with no data returned in the EVENT column is ON CPU.<\/p>\n
3) If I was going to ORDER BY something here, I suppose CLIENT_ID might be in there, but wouldn’t I be interested in ‘Most Active’? In which case, I would order by that TIME_WAITED column, if it wasn’t flawed. In fact, the smart thing to do here would be to COUNT the number of samples as a proxy for time. That’s what the supplied reports do and there are other examples over at ashmasters.com<\/a>.<\/p>\n
My final tip, though, would be this. If you run $ORACLE_HOME\/rdbms\/admin\/ashrpti.sql (note the i, it’s important), not only will it allow you to specify instance in a RAC cluster, but you can also limit the scope of the report in many interesting ways like this. (Although why anyone would want to report on WATI_CLASS is beyond me 😉)<\/p>\n
Specify SESSION_ID (eg: from V$SESSION.SID) report target:\nDefaults to NULL:\nEnter value for target_session_id:\nSESSION report target specified:\n\nSpecify SQL_ID (eg: from V$SQL.SQL_ID) report target:\nDefaults to NULL: (% and _ wildcards allowed)\nEnter value for target_sql_id:\nSQL report target specified:\n\nSpecify WATI_CLASS name (eg: from V$EVENT_NAME.WAIT_CLASS) report target:\n[Enter 'CPU' to investigate CPU usage]\nDefaults to NULL: (% and _ wildcards allowed)\nEnter value for target_wait_class:\nWAIT_CLASS report target specified:\n\nSpecify SERVICE_HASH (eg: from V$ACTIVE_SERVICES.NAME_HASH) report target:\nDefaults to NULL:\nEnter value for target_service_hash:\nSERVICE report target specified:\n\nSpecify MODULE name (eg: from V$SESSION.MODULE) report target:\nDefaults to NULL: (% and _ wildcards allowed)\nEnter value for target_module_name:\nMODULE report target specified:\n\nSpecify ACTION name (eg: from V$SESSION.ACTION) report target:\nDefaults to NULL: (% and _ wildcards allowed)\nEnter value for target_action_name:\n<\/pre>\n
In other words, Oracle already supply a report that does everything that query is trying to do and in my opinion, much better. I hope I don’t seem too critical but I’m trying to help people here and SUMs of timing information in ASH data has become a particular bug-bear of mine.<\/p>\n","protected":false},"excerpt":{"rendered":"
Some features in this post require a Diagnostics Pack license. I noticed a post on H.Tongu\u00e7 Y\u0131lmaz’s blog about filtering ASH data to look at the actions of a specific instrumented query. There are a few strange things that I was going to comment on but the blog requires me to use a WordPress account… Continue reading Session Level ASH Reports<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"class_list":["post-1505","post","type-post","status-publish","format-standard","hentry","category-uncategorized","entry"],"jetpack_featured_media_url":"","jetpack-related-posts":[{"id":1413,"url":"http:\/\/orcldoug.com\/blog\/2008\/05\/25\/good-news-for-ash-fans\/","url_meta":{"origin":1505,"position":0},"title":"Good News for ASH Fans","date":"May 25, 2008","format":false,"excerpt":"Damn. I wish Alex had written this blog posting a few days earlier.During the 10g performance screens presentation, I pointed people to Kyle Haileys website as usual, because there's some excellent related material on there, including ASHMON and Simulated ASH. I always mention the latter for those who aren't on\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1308,"url":"http:\/\/orcldoug.com\/blog\/2007\/08\/11\/does-anyone-know-when-11g-will-be-released\/","url_meta":{"origin":1505,"position":1},"title":"Does Anyone Know When 11g Will Be Released?","date":"August 11, 2007","format":false,"excerpt":"Sorry, I shouldn't be so sarcastic, but try to show some sympathy for my schedule.Thursday 9th August 22:30 BST - Go to bed, unusually early.Friday 10th 06:00 BST - Wake up, check Netvibes and noticed several 11g release blogs, including Eddie's initial notification and Howard's installation!07:30 BST - Leave for\u2026","rel":"","context":"With 4 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1477,"url":"http:\/\/orcldoug.com\/blog\/2009\/03\/30\/diagnosing-locking-problems-using-ash-part-1\/","url_meta":{"origin":1505,"position":2},"title":"Diagnosing Locking Problems using ASH – Part 1","date":"March 30, 2009","format":false,"excerpt":"Some features in this post require a Diagnostics Pack license.There are few better illustrations of the utility of ASH data than the ability to detect and diagnose locking problems*, even after they've occurred. Because ASH is sampling all active sessions all of the time, you should have information both for\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1515,"url":"http:\/\/orcldoug.com\/blog\/2009\/09\/01\/11-2-release\/","url_meta":{"origin":1505,"position":3},"title":"11.2 Release","date":"September 1, 2009","format":false,"excerpt":"Some features in this post require a Diagnostics Pack license. I noticed my Netvibes home page light up today with the release of 11.2 on OTN (Greg's is just one of a bunch of posts) - official home page here.More important to me was the documentation and there were two\u2026","rel":"","context":"With 27 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1669,"url":"http:\/\/orcldoug.com\/blog\/2012\/01\/10\/ukoug-2011-ash-outliers\/","url_meta":{"origin":1505,"position":4},"title":"UKOUG 2011 – Ash Outliers","date":"January 10, 2012","format":false,"excerpt":"My final UKOUG 2011 post is about another of my favourite presentations -\u00a0 \"ASH Outliers: Detecting Unusual Events in Active Session History\" by John Beresniewicz. (JB for short, but Marco Gralike made a fairly good stab at pronouncing his surname correctly during the introduction.)I'd been looking forward to this presentation\u2026","rel":"","context":"With 11 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1586,"url":"http:\/\/orcldoug.com\/blog\/2010\/03\/16\/hotsos-2010-day-5-training-day-with-tanel-poder\/","url_meta":{"origin":1505,"position":5},"title":"Hotsos 2010 – Day 5 – Training Day with Tanel Poder","date":"March 16, 2010","format":false,"excerpt":"I generally wouldn't visit the Hotsos Training Day, mainly because I've been away from home and work for long enough, particularly when you add the travelling time at either end, but this time I was determined to attend because Tanel was presenting.It was a busy room with a very high\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]}],"_links":{"self":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1505","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/comments?post=1505"}],"version-history":[{"count":0,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1505\/revisions"}],"wp:attachment":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/media?parent=1505"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/categories?post=1505"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/tags?post=1505"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}