{"id":73229,"date":"2013-08-07T10:09:59","date_gmt":"2013-08-07T10:09:59","guid":{"rendered":"https:\/\/www.red-gate.com\/simple-talk\/uncategorized\/introduction-to-instrumentation\/"},"modified":"2021-07-14T13:07:39","modified_gmt":"2021-07-14T13:07:39","slug":"introduction-to-instrumentation","status":"publish","type":"post","link":"https:\/\/www.red-gate.com\/simple-talk\/databases\/oracle-databases\/introduction-to-instrumentation\/","title":{"rendered":"Introduction to Instrumentation"},"content":{"rendered":"<p>The forest is thick with menace. The sunlight barely breaks through the leaves and is sludgy like curdled milk; the shadows of the branches look like gnarly fingers reaching to grasp at the pair of frightened small children.<\/p>\n<p>As they wind down the path, Hansel leaves a trail of pebbles. \u201cIt will help us find our way home,\u201d he says to Gretel, his voice quavering with fear.<\/p>\n<p>There is a parallel somewhere in there with the world of Oracle, believe me. I know that you\u2019re unlikely to be eaten by an ugly, wicked witch while writing PL\/SQL (I can\u2019t give you the same guarantees with C#), but think of Hansel\u2019s pebbles as debug messages, think of it as instrumentation.<\/p>\n<p>Instrumentation is the practice of measuring the progress of your application\u2019s performance as it runs, and is usually pre-baked into the software at the time the code is being written.\u00a0 It is, of course, not a uniquely Oracle concept, but Oracle is all I know and all I will talk about in this article. So, if you got here by googling \u201cHansel and Gretel\u201d, you may wish to leave now.<\/p>\n<h4>Do you need instrumentation?<\/h4>\n<p>If you\u2019ve ever asked:<\/p>\n<ul>\n<li>Why is my application suddenly performing so poorly?<\/li>\n<li>Which of my procedures needs tuning?<\/li>\n<li>Where exactly is my application crashing?<\/li>\n<li>What exactly is my code doing?<\/li>\n<\/ul>\n<p>Or if you\u2019ve ever said:<\/p>\n<ul>\n<li><i>Aaaaargh!<\/i><\/li>\n<\/ul>\n<p>Then you probably do need instrumentation.<\/p>\n<h4>What is instrumentation?<\/h4>\n<p>Instrumentation, very simply put, is the practice of including your debugging into your code as the code is being written, and not after the fact, after the crash\/issue\/problem has happened. This way, when you need to understand what your code is doing, you can simply run your application and examine your logs.<\/p>\n<h4>What to instrument?<\/h4>\n<p>No one understands your code as well as you do (I hope!) and so no one can supply you a full list of what information you want to capture in your instrumentation.\u00a0 However, the following are some practices that are generally accepted as wise.<\/p>\n<ul>\n<li>Include instrumentation at the entry point of every procedure and function that you write.\u00a0 The entry point, obviously, would be the first line after the BEGIN.<\/li>\n<li>Include instrumentation at the exit point of every procedure and every function that you write. The exit point of your procedures is right before your exception handling . Secondly,\u00a0 I\u2019m not your mother and so I don\u2019t want to nag you, but I do hope that your functions generally have only one exit point \u2013 one RETURN \u2013 and are not littered with RETURNs within conditional statements and other digressions.\u00a0 However, you should include instrumentation right before every exit point.<\/li>\n<li>If your routine accepts any parameters, you should include instrumentation outputting the values passed to each of these parameters.<\/li>\n<li>You will want instrumentation within your exception handling. You will definitely want to know if your code has raised an exception, and you will want to know what it was. Some Oracle experts argue that you should never have WHEN OTHERS THEN exception handling in your code. However, it may be a good idea to include it, instrument the exception, and then re-raise it.<\/li>\n<li>Instrument any significant points within the body of your code.\u00a0 Got a conditional statement? Then instrument the various paths within it. Writing a cursor? Then instrument any parameters it takes and any output it spits out.<\/li>\n<li>You may also want to include a debug message logging the SQL%ROWCOUNT after significant DML.<\/li>\n<\/ul>\n<h4>How to instrument<\/h4>\n<p>Now we know where to put our debug messages, we need to agree on what they should say. As performance measurement is such a huge part of instrumentation, it is a good idea for each debug message to log the SYSTIMESTAMP by default. That way, a simple look at the timestamps at the entry and exit points of a procedure can tell you if it is taking far too long to run.<\/p>\n<p>Entry and exit point debug messages should also, obviously, include the name of the procedure or function they are bookending. It should be immediately obvious from the logs your debug messages create when a procedure is entered and when it is exited, and which other procedures and functions it may call along the way. You may wish to use $$PLSQL_UNIT to put out the package name, alongside the name of the actual procedure or function.<\/p>\n<p>In addition to $$PLSQL_UNIT, Oracle provides a number of neat literals and functions that we can use in our instrumentation. SYS_CONTEXT is a veritable candy shop of session and environmental information. Dive in and go crazy.<\/p>\n<h4>Decisions you will need to make<\/h4>\n<ul>\n<li>Should your instrumentation always be on or should it be off by default and only run when you switch it on? There\u2019s an argument for both approaches \u2013 hopefully, your application won\u2019t fail often, so why do you want to swamp your hard drives with unnecessary data? However, if you <i>don\u2019t<\/i> automatically instrument your code, you won\u2019t have any logs to inspect after your application crashes. My personal preference is a compromise: automatically instrument all code, but also automatically delete the logs after a week or so.<\/li>\n<li>Should you write your instrumentation to a table or to log files? Again I would say go with your personal preference; arguments can be made for both.<\/li>\n<\/ul>\n<h4>Why NOT to instrument your code<\/h4>\n<p>Here are the arguments usually employed against instrumentation:<\/p>\n<ul>\n<li><i>What about the overhead created by all that extra code? <\/i>\u00a0Good question; however, a very simple test will demonstrate that sensible instrumentation does not create much, if any, overhead. Write a process with and without instrumentation and time its execution \u2013 barely any difference.<\/li>\n<li><i>Doesn\u2019t it make software more expensive to produce? <\/i>Yes, it does increase the upfront cost of production, since developers will take additional time to include instrumentation.\u00a0 However, the savings you make in maintenance will more than cover these costs.<\/li>\n<li><i>Why add instrumentation to code that we know will never fail?<\/i> This argument runs thus: this procedure is only 5 (or 10 or 100) \u00a0lines long, it is obvious it will never fail, so why waste time debugging it? No one writes code that they expect to fail, do they? Instrument everything.<\/li>\n<li><i>It\u2019s boring! It\u2019s not sexy! <\/i>That\u2019s true. But no one thinks seat belts are sexy \u2013 until they\u2019re in a car crash.<\/li>\n<\/ul>\n<p>However, you will want to do your utmost to reduce the cost \u2013\u00a0and boredom\u00a0\u2013 of instrumentation. I, for instance, named my instrumentation package <i>de<\/i> and the instrumentation procedure <i>bug,<\/i> making it as short as is sensibly possible to type (since I will be typing it a lot). Additionally, my <i>de.bug<\/i> procedure records systimestamp, $$PLSQL_UNIT, $$PLSQL_LINE, USER, sys_context(\u2018USERENV\u2019,\u2019SESSIONID\u2019), sys_context(\u2018USERENV\u2019,\u2019HOST\u2019) and a wealth of other data by default. That way, I do not need to do a lot of instrumentation to get a lot of information about the procedure I am executing.<\/p>\n<h4>Conclusion<\/h4>\n<p>There has been no sample code in this article because discussions about instrumentation are never about <i>how<\/i>, they are always about <i>why.<\/i> In fact, they are never <i>really<\/i> about why: it\u2019s like eating your greens or brushing your teeth at night \u2013 we all know we need to do it, but sometimes we need re-convincing. Instrumentation is always going to seem like a chore \u2013 right up to that moment when it saves our lives.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>The forest is thick with menace. The sunlight barely breaks through the leaves and is sludgy like curdled milk; the shadows of the branches look like gnarly fingers reaching to grasp at the pair of frightened small children. As they wind down the path, Hansel leaves a trail of pebbles. \u201cIt will help us find our way home,\u201d he says&hellip;<\/p>\n","protected":false},"author":221907,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"_acf_changed":false,"footnotes":""},"categories":[143533],"tags":[],"coauthors":[],"class_list":["post-73229","post","type-post","status-publish","format-standard","hentry","category-oracle-databases"],"acf":[],"_links":{"self":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/73229","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/users\/221907"}],"replies":[{"embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/comments?post=73229"}],"version-history":[{"count":1,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/73229\/revisions"}],"predecessor-version":[{"id":91712,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/posts\/73229\/revisions\/91712"}],"wp:attachment":[{"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/media?parent=73229"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/categories?post=73229"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/tags?post=73229"},{"taxonomy":"author","embeddable":true,"href":"https:\/\/www.red-gate.com\/simple-talk\/wp-json\/wp\/v2\/coauthors?post=73229"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}