{"id":1614,"date":"2010-10-03T12:00:00","date_gmt":"2010-10-03T12:00:00","guid":{"rendered":"http:\/\/orcldoug.com\/blog\/?p=1614"},"modified":"2010-10-03T12:00:00","modified_gmt":"2010-10-03T12:00:00","slug":"network-events-in-ash","status":"publish","type":"post","link":"http:\/\/orcldoug.com\/blog\/2010\/10\/03\/network-events-in-ash\/","title":{"rendered":"Network Events in ASH"},"content":{"rendered":"

Note – using ASH and the Top Activity screen require the use of the Diagnostics Pack License.<\/em><\/p>\n

This post was prompted by yet another performance problem identified using
\npretty pictures and Active Session History data. Although, as you’ll see, some
\npretty old-fashioned tools played their part too!<\/p>\n

ASH entries only exist for certain SQL*Net events. As usual, I think the
\ndesign is very successful as long as you have a basic understanding of how ASH
\nworks.<\/p>\n

The events all fall into one of three wait classes – Application, Network
\nand Idle. <\/p>\n

SQL> select wait_class, name from v$event_name where name like 'SQL*Net%' order by 1, 2;\n\nWAIT_CLASS\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 NAME\n-------------------- ----------------------------------------\nApplication\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net break\/reset to client\nApplication\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net break\/reset to dblink\nIdle\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net message from client\nIdle\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector message from client\nIdle\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector message from dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net message from dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net message to client\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net message to dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net more data from client\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net more data from dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net more data to client\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net more data to dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector data from client\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector data from dblink\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector data to client\nNetwork\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 SQL*Net vector data to dblink\n\n16 rows selected.\n<\/pre>\n
Hopefully that immediately dismisses the suggestion I’ve heard a few times that ASH\/Top Activity ignores SQL*Net events. However, there are<\/em> some events that are classed as Idle here that will not be captured in ASH data and will therefore not appear in the Top Activity screen. (In fact, even if you were to set the _ash_sample_all parameter you would not see these events in the Top Activity screen, even though ASH would contain entries for them. There is an additional filter applied to the data before it’s displayed. In any case, I would *not* recommend setting _ash_sample_all except for fun.)<\/p>\n
The most contentious of these is probably
\nSQL*Net message from client. This event indicates that the Oracle server is
\nwaiting for the client to\u00a0 do something. If the client is a user session, Oracle
\nis waiting for the user to do something – perhaps someone has a sql*plus session open that they’re doing nothing with or they are filling in an application screen with data? From an Oracle perspective that session
\nis Idle and there isn’t much we can do to tune it, including the waits would heavily skew the data we’re using for our analysis and, because events in the Idle
\nclass are specifically excluded from both ASH data and the OEM performance
\npages,\u00a0 such activity won’t appear. That seems sensible to me.<\/p>\n
However, if the client is actually an application server,
\nthose supposedly idle events can tell us something about end-to-end system
\nperformance. This blog post<\/a> describes one real life situation where that event
\nhelped me identify the performance problem.<\/p>\n
Back to the problem at hand. Sadly, in the midst of a a very chaotic work situation, I didn’t manage to grab any of the graphs in question but we had a persistent problem with our critical batch processes spending time waiting on ‘SQL*Net more data from client’, which showed up very clearly as network class waits. <\/p>\n
Now there are a number of reasons why this might be happening. Just a couple off the top of my head<\/p>\n
1) There is a performance problem with the application server so Oracle is expecting more data to arrive more quickly than the app server can deliver it.<\/p>\n
2) A network problem is affecting the delivery speed.<\/p>\n
Although the issue here turned out to be number 2, I suppose the true underlying issue is that this application is insanely ‘chatty’ and uses very frequent round trips to deliver data. Maybe the application design could be improved first?<\/p>\n
Ultimately we enabled Extended Tracing on the relevant sessions and confirmed that, yes, the sessions were spending most of their time waiting for the next batch of data and also how long these waits were. In practise, I’m not sure how much value the trace files added in this particular case. In fact, I think this is an excellent example of the underlying beauty of the sampling approach. As an event became *slower* it appeared *more often* in the samples and we had plenty of examples of how long some of the waits were. (But only some – probably the longest ones.)<\/p>\n
How did we solve this mysterious problem? With two very useful tools<\/p>\n
– ping\/tracert. I simply went on to the app server, pinged the db server and confirmed that the response time (from my memory) was in the range of 70-80 milliseconds – far higher than I would expect. One of the Java developers then ran a trace route to the server which highlighted that network performance was great until we hit the db server. It turned out that one of the network interface cards had auto-negotiated down to 100M\/s and this was the root cause – easily fixed. Sometimes old-fashioned and simple tools are all that you need, once you know where you should focus your attention (and ASH is great at focussing attention in the right place).<\/p>\n
– The next tool is one of the reasons I wanted to write this post. What made me try ping? Whilst I would have got there eventually, I thought I would try my performance optimisation secret weapon! One just for the database wizards! Something I’ve been keeping an eye on is Oracle Support’s attempt to give people a methodical approach to solving performance issues via the Oracle Performance Diagnostic Guide on My Oracle Support – Note ID 390374.1. There are several guides on that landing page but here is the link to the Slow Performance PDF<\/a>. (You’ll need an account to be able to access this.) This is an example of the kind of advice there. (Note that this is for SQL*Net message from client, but you would tend to get most events together anyway and there’s similar advice for more data from client.)

<\/em><\/p>\n
“Cause Identified: Slow network limiting the response time between client and database.<\/em>
The network is saturated and this is limiting the ability of the client and database to communicate with each other.<\/em>
Cause Justification<\/em>
TKProf:<\/em>
1. SQL*Net message from client waits are a large part of the overall time (see the overall summary<\/em>
section)<\/em>
2. Array operations are used. This is seen when there are more than 5 rows per execution on average (divide total rows by total execution calls for both recursive and non-recursive calls)<\/em>
3. The average time for a ping is about equal to twice the average time for a SQL*Net message from client wait and this time is more than a few milliseconds. This indicates that most of the client time is spent in the network.<\/strong>“<\/em><\/p><\/blockquote>\n
I’ve been loathe to mention this document until now because it looks like a work in progress (albeit not updated since the start of 2009), isn’t perfect, has gaps and I can imagine a number of my peers taking issue with some of the content. But for something to aid learning if you’re not naturally great at solving performance problems, I can think of much worse starting places. <\/p>\n
In the end, what could have been a really tricky performance problem (and might have taken a while to notice) was apparent with a brief glance at OEM and we could then follow up by applying the right analysis tools to the problem.<\/p>\n
To finish off, when I searched Google for any examples of ‘SQL*Net more data from client’, one of the first results that cropped up was a chapter from one of my favourite books<\/a> – ‘Optimising Oracle Performance’ by Cary Millsap and Jeff Holt. Well worth a read ….<\/p>\n","protected":false},"excerpt":{"rendered":"
Note – using ASH and the Top Activity screen require the use of the Diagnostics Pack License. This post was prompted by yet another performance problem identified using pretty pictures and Active Session History data. Although, as you’ll see, some pretty old-fashioned tools played their part too! ASH entries only exist for certain SQL*Net events.… Continue reading Network Events in ASH<\/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-1614","post","type-post","status-publish","format-standard","hentry","category-uncategorized","entry"],"jetpack_featured_media_url":"","jetpack-related-posts":[{"id":1481,"url":"http:\/\/orcldoug.com\/blog\/2009\/04\/09\/diagnosing-locking-problems-using-ash-part-4\/","url_meta":{"origin":1614,"position":0},"title":"Diagnosing Locking Problems using ASH \u2013 Part 4","date":"April 9, 2009","format":false,"excerpt":"Some features in this post require a Diagnostics Pack license.No sooner had I finished part 3 with some conclusions than I thought of another example I should have included and then someone else made a comment in an email which suggested another. (Thanks, JB!) \"It's probably worth pointing out that\u2026","rel":"","context":"Similar post","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":1614,"position":1},"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":1478,"url":"http:\/\/orcldoug.com\/blog\/2009\/03\/30\/diagnosing-locking-problems-using-ash-part-2\/","url_meta":{"origin":1614,"position":2},"title":"Diagnosing Locking Problems using ASH – Part 2","date":"March 30, 2009","format":false,"excerpt":"Some features in this post require a Diagnostics Pack license.I tried the graphical approach to tracking down the root cause of a locking problem in the last part. Now let's look at the underlying ASH data. I ran the same test after bouncing my test instance to start from a\u2026","rel":"","context":"With 3 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1480,"url":"http:\/\/orcldoug.com\/blog\/2009\/03\/31\/diagnosing-locking-problems-using-ash-part-3\/","url_meta":{"origin":1614,"position":3},"title":"Diagnosing Locking Problems using ASH – Part 3","date":"March 31, 2009","format":false,"excerpt":"Some features in this post require a Diagnostics Pack license.In the last part I described a locking scenario where the blocking session had only executed one SQL statement that was quick enough to avoid being sampled by ASH and is now inactive. As a result, there is no ASH data\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1495,"url":"http:\/\/orcldoug.com\/blog\/2009\/05\/01\/diagnosing-locking-problems-using-ashlogminer-the-end\/","url_meta":{"origin":1614,"position":4},"title":"Diagnosing Locking Problems using ASH\/LogMiner \u2013 The End","date":"May 1, 2009","format":false,"excerpt":"Except\u00a0it's not the\u00a0end, of course. What I mean is\u00a0that I usually agree with\u00a0what Miladin Modrakovic said in one of his comments on his first deadlock blog post.\"There is always way around.\"As I keep saying, there are many different ways of diagnosing locking problems. Which one works best\u00a0depends on the situation\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":893,"url":"http:\/\/orcldoug.com\/blog\/2005\/12\/19\/another-10046-success\/","url_meta":{"origin":1614,"position":5},"title":"Another 10046 Success","date":"December 19, 2005","format":false,"excerpt":"We're implementing a new packaged application at work. It includes a history import job that takes data in a flat-file and loads it into database tables. It performs some degree of data transformation but, in essence it inserts about 500,000 rows into one table and thousands in to a few\u2026","rel":"","context":"With 7 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]}],"_links":{"self":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1614","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=1614"}],"version-history":[{"count":0,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1614\/revisions"}],"wp:attachment":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/media?parent=1614"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/categories?post=1614"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/tags?post=1614"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}