Friday 26 August 2011

Whats the DBMS_OUTPUT Overhead

Question:
What is the overhead involved in having DBMS_OUTPUT calls in production code where serveroutput is turned off? I've read about how to selectively call or compile code, but I can't find anything that says, "Yes, there is considerable overhead in making DBMS_OUTPUT calls; conditionally skip them where possible" or "No, there is minimal impact; don't go to the effort of trying to conditionally make the calls."
Answer:
What a fine and very practical question you ask.
Before I answer it, I'll briefly describe how DBMS_OUTPUT works and provide some information about tracing.
How DBMS_OUTPUT works. The DBMS_OUTPUT package provides a procedure (PUT_LINE) that writes text out to a buffer (an array in memory) if output has been enabled. Host environments like SQL*Plus can then call the DBMS_OUTPUT.GET_LINES procedure to retrieve the contents of the buffer and display those strings through some kind of visual interface. DBMS_OUTPUT is, therefore, only useful when executing code from an environment that can/will display output from this built-in package.
DBMS_OUTPUT is certainly the simplest and most direct means of seeing what is happening inside your PL/SQL subprogram. The need for the host environment to extract data from the buffer, however, limits the usefulness of DBMS_OUTPUT as a tracing mechanism.
Tracing issues and requirements. Tracing generally refers to implementing a mechanism in your code so that you can trace or watch what is going on in your code. Tracing is different, by the way, from debugging. When you trace, you run your application and gather information about its real-time behavior. Afterwards, you examine the trace to identify bugs. When you debug, you step through the code line by line and examine the goings-on in your code. This is a crucial technique for identifying the cause of a bug.
There are a variety of tracing scenarios:
• Development tracing. I want to trace the execution of my program during development, to understand, test, and debug the code thoroughly. I neither want nor need tracing in my production code.
• Production tracing. I need to include optional tracing in my production application. If a user reports a problem, I can then turn on tracing within production, gather the necessary information, and then perform my analysis.
• Tracing flexibility. In some simple cases, I can rely solely on DBMS_OUTPUT to display tracing data to the screen. In many other situations, however, I will want to use a different repository for my trace. For example, suppose my program runs for hours. I want to see the trace information while the program continues to execute. So I will write information out to a table using an autonomous transaction procedure. I can then see the output immediately from another session.
As with every other aspect of your application design, you should think through the kinds of tracing you need and the repositories in which the trace information must be written before you begin writing your application.
Test case Length of String Number of Calls Elapsed Time
(hundredths of seconds)
DBMS_OUTPUT enabled 10 1000000 767
DBMS_OUTPUT disabled 10 1000000 392
DBMS_OUTPUT enabled 10000 1000000 984
DBMS_OUTPUT disabled 10000 1000000 739
DBMS_OUTPUT disabled NULL 1000000 61
Call to DBMS_OUTPUT.PUT_LINE Removed N/A 1000000 11
Testing. To answer your question, I put together a script—located in Listing 4—to test the overhead of calling DBMS_OUTPUT.PUT_LINE. I explain it and the results in a bit more detail below, but I will first offer my conclusions to you:
1. The impact on application performance is (here comes one of those classically infuriating answers) application-specific. That is, a call to DBMS_OUTPUT.PUT_LINE all by itself doesn't incur very much overhead. (For example, over 100,000 invocations of my test code, calling DBMS_OUTPUT.PUT_LINE and passing NULL, took .61 seconds. Removing the call to this built-in reduced execution time to .11 seconds.) What can take a lot of time is evaluating the value that you pass to the single string parameter of DBMS_OUTPUT.PUT_LINE. More on this below.
2. The more important question when examining the issue of tracing in one's code is, "What is the best way to do it, from the standpoint of readability and maintainability of code?" (Hey, this is, after all, a best-practices column!) Generally, one's code is more readable when it is not littered with lots of calls to trace programs.
The results are in. Having said all that, let's now take a look at the results of my analysis of the overhead of calling DBMS_OUTPUT.PUT_LINE. I will then conclude with more best-practice- oriented comments.
To construct the script to analyze overhead in DBMS_OUTPUT.PUT_LINE in Listing 4, here is the approach I took:
• I used consecutive calls to DBMS_UTILITY.GET_CPU_TIME to compute elapsed time down to the hundredth of a second (you can substitute this program with DBMS_UTILITY.GET_TIME if you are not yet running Oracle Database 10g).
• I recorded the results in a database table, because DBMS_OUTPUT must be disabled for at least part of this script and is, in any case, the focus of our analysis and should not be used to record and display results.
• For most of the tests, I passed a string that requires some effort to construct each time the built-in is called. Specifically, I used RPAD to create a string of a length specified at the time the test is run, and concatenated to that a date and a Boolean. This may be more work than is usually performed when you call DBMS_OUTPUT.PUT_LINE, but it is surely not outside the realm of normal tracing activity.
• I called DBMS_OUTPUT.PUT_LINE with the following variations: output enabled, output disabled, pass just a NULL, and don't call DBMS_OUTPUT.PUT_LINE at all.
Table 1 shows what I found after running this script. As you can see, there is certainly overhead associated with calling DBMS_OUTPUT.PUT_LINE, and the scale of that overhead depends very much on the amount of work it takes to construct and pass the string to DBMS_OUTPUT.PUT_LINE. Is this overhead "considerable" or "minimal"? I cannot answer that question for you—it depends on your application.
Tracing recommendations. I offer the following tracing recommendations:
• Never call DBMS_OUTPUT.PUT_LINE directly in your application code. Create a wrapper that accepts the application data you want to see in your trace and then calls DBMS_OUTPUT.PUT_LINE. Why do I suggest this? Prior to Oracle Database 10g, DBMS_OUTPUT.PUT_LINE will raise an error if you try to display strings with more than 255 characters (that limit has now been raised to 32K). Also, you may want to send trace information to a file or table rather than the screen, and a direct call to DBMS_OUTPUT.PUT_LINE forces you to sacrifice that flexibility.
• If you are running Oracle Database 10g Release 2, take advantage of conditional compilation so that you can easily "compile out" the trace calls when your program goes into production (unless you need production-time tracing, of course). Now, one issue I believe you will currently encounter when using lots of conditional compilation statements in your code ($IF, $ENDIF, $ERROR, $$ccflagname, and so on) is that the code is harder to read. I expect, however, that the various PL/SQL editors, such as Toad, SQL Navigator, PL/SQL Developer, and—the latest entry—Oracle SQL Developer, will soon offer toggles to hide this logic as you are editing and reviewing your code, greatly improving that situation.
• If you are not yet running Oracle Database 10g Release 2, also consider enclosing trace calls inside your own conditional statement, which might look like this:
• IF trace_pkg.trace_enabled
• THEN
• trace_pkg.trace (l_my_data);
• END IF;
With this approach, the argument(s) passed to the trace mechanism will be evaluated only if tracing is enabled. You can, therefore, keep to an absolute minimum the overhead your application will experience when tracing is disabled.

No comments:

Post a Comment