How Do You Find the Needle Causing Problems in Your Haystack of Code? With a Big Magnet.

By Brian Arnold

We all know the old saying “It’s like finding a needle in a haystack.” You would have to dig through the entire haystack and maybe, if you are lucky, you will find the needle. This is just like trying to uncover performance problems in your LotusScript code. Unless you wrote the code, and even then, it can be very difficult to pinpoint what is causing the performance problems that your users are complaining about.

Just like finding that needle, there’s always a better, faster, smarter way. To find the needle you would simply use a big magnet to pull it out of the haystack. Using that method for your code, you can use Teamstudio Profiler to be the magnet for your LotusScript code.

As an example, I recently used Profiler to increase the performance of one of our own applications by 30%. In this blog post, I’ll show you how I did it.

But first, if you are unfamiliar with Profiler, allow me to explain what this tool can do. Profiler lets you see, at a glance, how every line of your LotusScript code is performing, so you can effectively pinpoint bottlenecks without the need for manual testing. Profiler’s comprehensive reporting gives you the peace of mind (and proof) that every line of code has been tested, and that flawed script won’t plague future generations of an application. Profiler presents performance data in a simple bar chart, so you can scan a report and quickly locate the laggards in your script. No manual timing statements. No stopwatches. Used during testing or development, Profiler greatly improves the likelihood that problems are eradicated before they hit production, resulting in solid, efficient applications that do everyone proud.

So how does Profiler work? Profiler runs in your HCL Notes client and monitors all LotusScript code in the functions you are running. Once Profiler has started, all of your usage within your Notes database is monitored for LotusScript performance timing. Once you stop Profiler you are presented with the timing results of the LotusScript functions which ran while it was enabled.

Here’s my example of how to use Profiler to track down performance issues. In this example I am using a utility that we built for another product, Teamstudio Adviser. The utility creates a CSV extraction of the data contained within the Adviser tool. The LotusScript functions load into memory all of the details about the data the user wants to extract, accesses the Adviser database to obtain the data, performs specific joins to the data and then creates a CSV file. Depending on the amount of data contained within the Adviser database we found that when there is a large amount of data (in excess of 500,000 documents) the process was very time consuming. Notes is not well known for processing large numbers of documents, but this is the core functionality in the utility, so we needed to find out what was taking the most amount of time.

To start Profiler, I simply open the Notes database to where the functionality I want to time is located. Then I click on the Profiler Toolbar icon to start the process. I am presented with the following dialog:

From the moment I click the “Begin” button Profiler will monitor and calculate how long any LotusScript code that the Notes client triggers takes to run.

Once it is in the monitoring mode, I can then run the LotusScript code that I want to time. In my case I have a button on my form which runs an Agent. The Agent is where the code that creates the CSV file is contained. At this point I allow the agent to run its processes and once it is done, I again click on the Profiler Toolbar icon to stop the monitoring process.

Then I am presented with the results as shown below:

I can very quickly determine that there is one Function called “FN02_CREATEDATAARRAY” which is taking up the most amount of time in the agent, in this case close to 43% of the time is spent in this one function. This will be my starting point for investigation into performance issues. To see what is happening within that function I simply select it from the top list. The bottom portion of the Profiler results will change to show any other functions or routines which are called from the parent function. We call these children of the parent function. In the bottom portion of the dialog there is also a tab labeled “Source”. When I click on that tab it will then show me the actual source code from the function along with timing for each line of code in the function:

When I scroll through the source code, I can also quickly determine which lines of code are taking the longest amount of time. In this case there is one line of code that is taking almost 35% of the overall time to run this function:

I have now essentially used Profiler as my magnet to home in on the one line of code that is causing the biggest performance degradation in my Agent, and all it took was to run the Agent once while Profiler was monitoring it to find this out. Subtracting the amount of time that the Agent actually took to run, once I had the timing results from Profiler, I was able to discover the line of code within less than a minute!

If I were to try to determine this same problem WITHOUT Profiler, I would have ended up having to write an excessive amount of extra code that would place pseudo timers throughout my code that would need to also write the results to somewhere that I could review it later. Even if I were to do this it could easily double my code if I wanted to time every line of my code. That would be incredibly time consuming in and of itself and may not report back the correct findings since this additional code would make the agent slower than it already is. And even if I did find the same line of code I would then have to go back through the agent and remove all of the timers that I placed into it. Not very efficient at all.

Now that I have the line of code, I can get busy at finding a better method for achieving my needs or change the existing method to be more time efficient. And, with all of the time saved by using Profiler to find the problem I have plenty of time to correct the issue!

In our case we were able to improve the length of time the agent takes to run by addressing some performance issues in the view being referenced in the LotusScript call to create the view navigator. Specifically, we changed all @Formula processing in the view columns so that the data was provided without pre-processing and instead performed any processing of the column values in the agent itself. This change improved the performance by approximately 30%!

Now if you start thinking of all the LotusScript code that you’ve already written, you could easily use Profiler to breathe new life into some of your older but still heavily used Notes database applications. You never know, they might start seeing increased usage in your old apps just by improving their performance!

To learn more about Profiler, click below.