Introduction to Instrumentation

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. “It will help us find our way home,” he says

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. “It will help us find our way home,” he says to Gretel, his voice quavering with fear.

There is a parallel somewhere in there with the world of Oracle, believe me. I know that you’re unlikely to be eaten by an ugly, wicked witch while writing PL/SQL (I can’t give you the same guarantees with C#), but think of Hansel’s pebbles as debug messages, think of it as instrumentation.

Instrumentation is the practice of measuring the progress of your application’s performance as it runs, and is usually pre-baked into the software at the time the code is being written.  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 “Hansel and Gretel”, you may wish to leave now.

Do you need instrumentation?

If you’ve ever asked:

  • Why is my application suddenly performing so poorly?
  • Which of my procedures needs tuning?
  • Where exactly is my application crashing?
  • What exactly is my code doing?

Or if you’ve ever said:

  • Aaaaargh!

Then you probably do need instrumentation.

What is instrumentation?

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.

What to instrument?

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.  However, the following are some practices that are generally accepted as wise.

  • Include instrumentation at the entry point of every procedure and function that you write.  The entry point, obviously, would be the first line after the BEGIN.
  • 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,  I’m not your mother and so I don’t want to nag you, but I do hope that your functions generally have only one exit point – one RETURN – and are not littered with RETURNs within conditional statements and other digressions.  However, you should include instrumentation right before every exit point.
  • If your routine accepts any parameters, you should include instrumentation outputting the values passed to each of these parameters.
  • 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.
  • Instrument any significant points within the body of your code.  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.
  • You may also want to include a debug message logging the SQL%ROWCOUNT after significant DML.

How to instrument

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.

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.

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.

Decisions you will need to make

  • Should your instrumentation always be on or should it be off by default and only run when you switch it on? There’s an argument for both approaches – hopefully, your application won’t fail often, so why do you want to swamp your hard drives with unnecessary data? However, if you don’t automatically instrument your code, you won’t 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.
  • 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.

Why NOT to instrument your code

Here are the arguments usually employed against instrumentation:

  • What about the overhead created by all that extra code?  Good 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 – barely any difference.
  • Doesn’t it make software more expensive to produce? Yes, it does increase the upfront cost of production, since developers will take additional time to include instrumentation.  However, the savings you make in maintenance will more than cover these costs.
  • Why add instrumentation to code that we know will never fail? This argument runs thus: this procedure is only 5 (or 10 or 100)  lines 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.
  • It’s boring! It’s not sexy! That’s true. But no one thinks seat belts are sexy – until they’re in a car crash.

However, you will want to do your utmost to reduce the cost – and boredom – of instrumentation. I, for instance, named my instrumentation package de and the instrumentation procedure bug, making it as short as is sensibly possible to type (since I will be typing it a lot). Additionally, my de.bug procedure records systimestamp, $$PLSQL_UNIT, $$PLSQL_LINE, USER, sys_context(‘USERENV’,’SESSIONID’), sys_context(‘USERENV’,’HOST’) 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.

Conclusion

There has been no sample code in this article because discussions about instrumentation are never about how, they are always about why. In fact, they are never really about why: it’s like eating your greens or brushing your teeth at night – we all know we need to do it, but sometimes we need re-convincing. Instrumentation is always going to seem like a chore – right up to that moment when it saves our lives.