Soon after you get a program up and running, one of the first requests you'll have to deal with is, "Can you make it run faster?" If you quickly threw the application together, you probably have some ideas about sections of code that you know could benefit from some rewriting. However, if you took some time putting the code together, there may not be any obvious improvements you can make. At this point, you'll need to profile the code to see which sections are taking the most time. Unfortunately, most of the commercially available code-profiling tools are lavishly expensive, although most offer an evaluation version.

Before investing in a tool, you can follow the time-honored tradition of "rolling your own." In this article, I'll show you some quick techniques that my team came up with that helped us discern the trouble spots in our code. Best of all, it took only a few minutes to add the code to our application so that we could better understand how it was running.

Gross Time

To start with, you need to understand that the timing tools that I'll describe provide what I call "gross" measures of time. That is, we can measure timings down to hundredths or thousandths of a second using the .NET System.DateTime.Now value. The documentation for the Now property indicates that it measures time using a unit of measure called a "tick," which is 100 nanoseconds. However, other resources on the web state that Now is only accurate to 16/1000 of a second.

For some coding tasks, you will need greater precision of timing. For what we were doing, it was enough to get relative timings of sections of code. For example, one section of our code was divided into four subsections. The total time reported for the four subsections seemed to be about 1.5 seconds. When we loaded a program, it hit that section of code 20 times. That correlated with our seat-of-the-pants experience that it was taking about 30 seconds to load the program. Being able to look at timings in greater precision would not have given us any greater insight: it was sure taking a long time to start the program! By dividing up the section into four sections and timing each one, we were able to identify possible areas of improvement.

Taking the Measure

To use our simplistic timer, we define a variable named StartTime as a System.DateTime data type. You can see this in the code example in Figure 1. For each section of code that I want to time, I set StartTime to DateTime.Now. In Figure 1, I set the StartTime for three operations (opening an iDB2Connection, executing an SQL command, and reading through the data reader). After each operation, I call the PrintTime subroutine, which is at the end of Figure 1.

The PrintTime subroutine takes a message as the first parameter and the StartTime value as the second parameter. The message can be any text; it is simply used to identify the event being timed.

In the PrintTime subroutine, I create an object named ts of type System.TimeSpan, initialized to the current value of Now (which is the "end time" of the event) minus the StartTime. In other words, the ts object contains the duration of the event. As I mentioned above, this is a gross duration, and I've made no attempt to factor out the overhead of calling the subroutine, creating the TimeSpan object, etc. I simply figure that for my purposes, that overhead is insignificant.

The final statement in the PrintTime subroutine writes to the Console. The message is displayed, along with the TimeSpan displayed as TotalSeconds. If you look into the MSDN documentation for the System.TimeSpan structure, you'll see that you have several options available to format the duration.

As a side note, the {0, -40} in the Console.WriteLine is used to format the message text as left-aligned within a 40-character space. Because I planned to call PrintTime several times in succession, I wanted the output to be displayed consistently, regardless of the message that I provided.

You can see an example of the output in Figure 2, which shows times for opening the connection and executing the SQL statement. These times occurred the first time I ran the program. On subsequent runs, the timings improved, which I attribute to the database sever code being resident in my System i memory.

Where Timing Doesn't Help

This simplistic timing mechanism is not that useful when timing sections of code that don't involve database I/O. The reason is that the timer reports either zero as the elapsed time or the smallest value that it can resolve down to (the smallest reported time value is 0.0100144). In some cases it has been useful to bracket large sections of code with a start-time and end-time value, but the timer I've shown will not be useful for small sections of VB or C# code.

Where Timing Does Help

However, our application uses some third-party code that we call out to. I bracketed several of those calls, which are single statements, with the start and end timer. In some cases, I could see that the calls improved with frequency of usage, as more code was paged into memory. Because the code we are using is not available in source code format, there is little that we can do to improve its performance. Again, though, I am not as interested in absolute timing numbers as I am in relative performance of the code in reference to other sections of code in my application. At least I have some data that can be used to compare those sections with the total response time, and using relative timing, determine if it is worth rethinking how the feature is used in my application.

Time Takes Time

Because it does take some time to take the time, you may want to consider bracketing the StartTime initializations with an if condition. You can also bracket the code within the PrintTime subroutine. It then becomes an easy matter of setting the if condition by using a value in your program, a property you set at runtime, or a value you pass in via the compiler. By leaving the timers in place, you're well equipped to start timing again when the need arises.

Craig Pelkie has worked as a programmer with IBM midrange computers for many years. He has also written and lectured extensively on AS/400 and System i technologies, including client/server programming, Client Access, Java WebSphere, .NET applications for the System i, and web development. You can reach him at craig@web400.com.