Archive

Posts Tagged ‘Profiler’

SamplingProfiler v1.7.5

September 2nd, 2010

A new version has been released which adds support for the new Delphi XE paths, you can download it here.

Note that there is still a pseudo-random issue of unknown origin under Windows 7, where the utility may or may not be able to gather profiling information. If that happens, close the application and launch it again. The issue doesn’t happen with Windows OSes before 7.

Eric News , ,

All hail the “const” parameters!

July 28th, 2010

Passing parameters as “const” is a classic Delphi optimization trick, but the mechanisms behind that “trick” go beyond cargo-cult recipes, and may actually stumble into the “good practice” territory.

Why does it work?

The most well known case is “const String“, for which the compiler than takes advantage of the “const” to pass the String reference directly (as a pointer)… and without increasing the reference counter.

To illustrate what the reference counting implies, here are two screen-shots from the CPU disassembly view, taken in Delphi 6, but the recent compilers up to Delphi 2010 at least behave in a similar fashion (just with the Unicode version of the functions).
I’ve made a pseudo-function, with only one String parameter that calls a single function (here Length(), which isn’t inlined in Delphi 6, and corresponds to LStrLen), guess which CPU disassembly corresponds to “Test(const a : String)” and which to “Test(a : String)

What you’re seeing on the left is an implicit try…finally construct which is used to protect the reference counting (LStrAddRef/LStrClr) on the implicit local variable used to store the String parameter. If you have such calls nested a few levels deep (not uncommon in object-oriented code), you could accumulate quite some overhead.
Also not see here but hidden within the AddRef and Clr calls are bus locks, which may hit you disproportionately in multi-threading scenarios.

And what if you’re modifying the passed String? Can you forego the “const“? Well no, the extra overhead is still there, and using a “const” still beneficial.

String isn’t the only type affected, there are similar gains for all reference counted types (interfaces, dynamic arrays, records holding reference-counted types). And when passing a record as “const“, there is an additional gain in the lack of defensive copying of the record (the larger the record, the greater the gain).

For ordinal and numeric types, there is no compiler optimization (yet), but it can be good practice to mark them as “const“, not in the optimistic hope that someday the compiler will optimize it, but to ease up debugging and code writing. Copies of those parameters (when you want to modify them in the function body) are typically handled adequately by the compiler (and often enough comes for free), so don’t let performance considerations hold you.

There is one case in which using “const” could have adverse effects, but it involves global variables which you would modify or release during the call… so you don’t really need to know more about it, do you? ;)

How does it manifests itself in Profiling?

A missing “const” can manifests itself in different ways during profiling, for String, Interface and dynamic array types, you’ll usually see it via the relevant xxxAddRef or xxxClr functions (the obvious case) and via time spent in begin/end (the less obvious case). Depending on how many functions calls with the reference counting are involved in your inner loop, none of the above may come ahead, even if calls and reference counting are an issue: the time spent will be spread over the above functions and your various begin/end sections.
For record parameters, the lack of “const” could materialize itself in “Move“, or other data copying costs (large records will be moved, smaller ones can be copied via ad-hoc in-place code by the compiler).

In multi-threading, things can be a little less obvious, as rather than the reference counting and exception frame, it could be the bus locks hitting you, or sometimes worse, inter-CPU traffic to pass around the values of the reference counter.

Multi-threading’s worst case would be referring to the same string field from multiple threads, and passing that string around in functions without “const” parameters, thus repeatedly hitting the reference counter of that string from multiple threads at the same time, resulting in extra inter-CPUs traffic to share the value of that reference counter.

In such cases, “const” can help, but it will often not be enough, you’ll also have to look for functions/methods that return strings with an unnecessary reference counting, like when getting your strings from a TStringList.

Good Practice

Usually I tend to “const” just about every parameter that isn’t “var” or an object, this isn’t just  to pre-emptively alleviate possible performance issues, but also to gain something valuable when debugging and writing a function’s body: untouched input parameters, wherever you are in the function’s body. This means not just in the function’s body, but also when in the functions called by the function.

And that’s the key point to remember about “const” parameter: it’s here to state that a parameter will be left unchanged inside the body, something which allows the compiler to optimize it’s output, and the developer to optimize his thought process too. Qualifying all your parameters as either “const” or “var” makes your intentions obvious.

So IME, it’s not worth it to hoard your keystrokes, best spend them on “const” and explicit local variables when you really need to alter those input parameters.
Whoever has to maintain your code will be thankful.

Object parameters

There is one case I’ve not mentioned in all the above, the case of object parameters (and class references). It’s a special case because when you pass an object as “const“, you’re not making any promises of not keeping the object constant, but just keeping the underlying variable (pointer) constant. This is unlike other languages. There is also a risk of confusion when your code will be read by developers not really familiar with the underlying pointer-based mechanics of objects (and they are more common than you may think, even, and maybe more so in highly OO languages).

So for objects, unless you want to spend a lot of time educating, my rule of thumb is to avoid “const” or “var” for object parameters.

Beyond “const” parameters

Const’ing your parameters will eliminate some defensive copying, implicit try…finally, and reference counting overhead, but it leaves open another field of similar inefficiencies: that of return values.

Alas there is no “const Result” syntax, which would allow to state that your result can’t be altered in any way (a sort of strict immutability if you will). Thus whenever you have a function returning a String f.i., you’ll end up triggering the implicit reference counting and exception machinery if you’re not careful (like in this case)…

There are strategies to tackle this issue, but none of them are as simple as adding a “const“, and most of them come with sacrifices… so, let them be food for other articles.

Eric Tips , , , , ,

SamplingProfiler v1.7.4

September 8th, 2009

SamplingProfiler v1.7.4 is now available. This version adds an option for Delphi 2010 paths, and fixes a bug with the silent mode execution that would render it inoperative. There also have been other minor changes, mostly cosmetic.

This release also includes preparation for an “attach to process” option, which is currently not enabled, but should hopefully make in the next version (available “when ready”).

Eric News , , ,

Profiling multi-threaded applications

May 27th, 2009

SamplingProfiler has a few options to help profile a multi-threaded application which I’ll go over here.

In the current version, those options allow identifying CPU-related bottlenecks, as in “threads taking too much CPU resources or execution time”. However, they do not provide much clues yet to pinpoint bottlenecks arising from thread synchronization issues or serialization (insufficient parallelism). Hopefully, more support for profiling multi-threaded applications will come in future versions.

Single-threaded profiling

By default, SamplingProfiler only looks at one thread, the main application thread, but you can manually (and dynamically) specify another thread. This is done via OutputDebugString (see Control sampling from your code)

OutputDebugString('SAMPLING THREAD threadID');

with threadID the thread ID (as returned from the WinAPI function GetCurrentThreadID f.i.). If you specify an invalid threadID, or if the thread dies, no more samples will be collected until you specify a new thread or “return” the sampling focus to the main thread, which can be accomplished with

OutputDebugString('SAMPLING THREAD 0');

This command is mostly useful if you already have a clue which thread is proving troublesome, like when a worker thread is used in GUI interface. If you have several worker threads in a thread pool, which serve random workloads (or assumed random),  you can pick one of those threads (at random) and have it profiled.

However, this involves a fair amount of bias and guessing where the bottleneck could be, and is not really applicable if you have a high number of threads working (or sleeping) simultaneously on multiple CPUs. This is where comes in…

Monte-Carlo Samples Gathering

Monte-Carlo sampling is specified via the samples gathering mode option, when set, SamplingProfiler will pick a random thread of the profiled application at each sampling, and use it for the sample. Bias and guessing are eliminated.

The good news is that with this method, the sampling load is not increased, and its impact is random: concurrency issues and UI bottlenecks can still be spotted. Hot-spots in a server running at production speed can be spotted too.

The bad news is that if you have a high number of inactive threads, you’ll have to gather more samples to get meaningful results on the active threads (as each time an inactive thread is picked at random, the sample will be meaningless, and thus lost).

Interpreting the profiling results can however be a little more difficult, as several multi-threading effects can come into play, for instance a drop in CPU cache efficiency (code stressed in highly threaded situations can behave quite differently from what it looks when stressed in single-threaded situation). This will be food for future articles.

To decide if a thread is active or not, SamplingProfiler looks at its registers: if all the registers are unchanged between two samplings, the thread is deemed inactive and the sample dropped. Inactivity can thus result from the thread being sleeping or waiting on some event, or just from having not gotten its share of CPU time since the last time it was sampled (this can be quite common if you have a much higher number of threads than you have CPU cores, even if all the threads are busy).

CPU Affinity

The last set of options is the one for processor affinities. You can choose on which CPUs SamplingProfiler is constrained, and on which CPUs the profiled application is constrained.

Affinities can be used either to further isolate the profiled application from the profiler, or to easily simulate your application running on a machine with less cores. In more advanced scenarios, if you have enough CPU cores, you can also leave CPU cores entirely unused by both the profiler or the profiled, and thus reserve them to a third application (such as a database server).

Eric Tips , , , , , ,

SamplingProfiler v1.7.3 bug fix

May 22nd, 2009

SamplingProfiler v1.7.3 has now been released and should be used in place of 1.7.2 which was pulled.

1.7.2 had a nasty bug in the timings statistics (promptly spotted by Robert Houdart) which should be fixed in 1.7.3, there are no other changes and additions in this version.

Eric News , ,

SamplingProfiler v1.7.2

May 20th, 2009

SamplingProfiler v1.7.2 has now been released.

This version includes the following changes:

  • added an option to display line numbers in the source preview
  • extended the process CPU affinity options to allow individually selecting up to 16 cores

The UI has been slightly rearrange to accomodate the CPU affinity options (I guess I’ll need to find something prettier for those upcoming 256 core CPUs…). There may be other indirect minor changes.

Eric News , , ,

Code Optimization: Go For the Jugular

May 6th, 2009

Code optimization can sometimes be experienced as a lengthy process, with disruptive effects on code readability and maintainability. For effective optimization, it is crucial to focus efforts on areas where minimal work and minimal changes will have to most impact, ie. go for the jugular


The Prey

I will illustrate this using SamplingProfiler in a small example, taken from a small library that deals with short vectors of varying length (but usually less than 10 dimensions), which I simplified, isolated & anonymized for the purpose of this article.

uses TypInfo;

type
   TDoWhat = (dwInc, dwDec);

procedure DoSomething1(var data : array of Integer; what : TDoWhat);
var
   i : Integer;
begin
   for i:=Low(data) to High(data) do
   begin
      case what of
         dwInc : Inc(data[i]);
         dwDec : Dec(data[i]);
      else
         raise Exception.Create('Unsupported: '+GetEnumName(TypeInfo(TDoWhat), Integer(what)));
      end;
   end;
end;


Get Meat into Belly

Before starting any kind of optimization, one has to define goals and limits, ie. figure out what “good enough” will be rather consider  “good enough” to be the state of the code one has grown tired of optimizing it!

The sample code above is quite straightforward and simple. It would of course be possible to blow this code to huge proportions for optimization’s sake. If you are after getting every last drop of CPU-cycle juice, and allow yourself to use every trick in the book, a fully optimized version could represent several thousandths of lines of code (I’m not exaggerating). If it’s your core business, it might be okay, but if it’s just a utility library, the increased maintainability issues could never be justified.

But since this article is intended more as an illustration than a discussion on the methodology, I’ll get straight to the buffalo (beef). For further reading on that subject, you can start from Big O Notation, Benchmarking and Software metrics articles in wikipedia, there are also whole books on the subject.


Stalking the Prey

Looking at the above code, the first obvious optimization that developers suggest seems to be taking the conditional out of the loop, resulting in several case-specific loops. On small vectors, this nets about a 30% speedup. For further speedups, the suggestions are typically to go for loop unrolling, asm, and other heavy-handed solutions that come with a significant development time and code complexity increase.

Of course, readers of this website will know better than to jump straight into the code and apply optimization recipes: they would run the code through a profiler first. And since we’re dealing with a single procedure, an instrumenting profiler would be of little help, so they would run Sampling Profiler instead, and would get to see something like this:

Going For The Jugular - Initial Profiling Results

In this run, only the dwInc case was stressed (line 37), and obviously the procedure spends less than 30% of its time doing what it was asked of, and most of its time (33%) on the “end“, ie. cleaning up, plus 8% setting up in “begin“. That’s 40%+ doing nothing but stack and setup/cleanup work!
The conditional in the loop that could have looked like the most worrying bit is eating a bit less than 20% of the time.

What is the source of all that begin/end work? Place a breakpoint on begin, run and hit Ctrl+Alt+C when your breakpoint is reached, go have a look at the CPU view, and you’ll see this:

Going For The Jugular - CPU view near "begin"

This is a fairly significant stack setup for such a small procedure, and those instructions with “fs:” at the bottom are the setting up of an (implicit) exception frame. An exception frame for what? if you haven’t guessed already, navigate your CPU view near the “end” line.

Going For The Jugular - CPU view near "end"

No wonder “end” was a bottleneck! The call to UStrArrayClr indicates that the exception frame is here to cleanup several strings… these strings are those of the raise Exception, one is the string returned by GetEnumName, the other is the result of the concatenation passed to Exception.Create.


Isolate and Kill

How to get rid of that exception frame? One typical way is to use “Exception.CreateFmt”, and pass only constant strings to it, but that is not possible here with the call to GetEnumName, which returns a string. The other way is to isolate the exception to its own (nested) procedure:

procedure RaiseUnsupported(what : TDoWhat);
begin
   raise Exception.Create('Unsupported: '+GetEnumName(TypeInfo(TDoWhat), Integer(what)));
end;

and call RaiseUnsupported in the “case else“. Doing so will move the exception frame to the new procedure, where it’s irrelevant in terms of performance.
This simple change nets us a 33% speedup, ie. we reclaimed most of the lost time in begin/end! We also gained a bit from the UStrArrayClr, which did essentially nothing since those strings it was used to clear weren’t defined (as long as we did not hit the exception).

Note that if you use a nested procedure for RaiseUnsupported, you can be tempted not to pass it the “what” parameter, but use directly the “what” from its parent procedure. However by doing so, you’ll have the compiler use a special stack setup (so that the nested procedure can access the parent procedure’s variables). This setup will be faster than the exception frame it replaces, but with it, begin/end would still be taking about 18% of the CPU time spent in the procedure.


Repeat Until Belly.Full;

Those first 33% were easily gained. Let’s go for another round of SamplingProfiler:

Going For The Jugular - Further Profiling Results

Things are more satisfying: the line performing the actual work is now taking up most of the CPU time. Second comes the case of line. For further speed improvements, we now need to move the conditional out of the loop:

procedure DoSomething3(var data : array of Integer; what : TDoWhat);

   procedure RaiseUnsupported(what : TDoWhat);
   begin
      raise Exception.Create('Unsupported: '+GetEnumName(TypeInfo(TDoWhat), Integer(what)));
   end;

var
   i : Integer;
begin
   case what of
      dwInc :
         for i:=Low(data) to High(data) do
            Inc(data[i]);
      dwDec :
         for i:=Low(data) to High(data) do
            Dec(data[i]);
   else
      RaiseUnsupported(what);
   end;
end;

We have increased the line count noticeably, but most of those extra lines are still cosmetic. What further makes it a reasonable trade-off is that the execution time has been reduced by 66% from the initial version, it now executes 3 times faster!

Are there any more easy gains to be had? Let’s run the last version through SamplingProfiler:

Going For The Jugular - Final Profiling Results

More than 92% of the execution time now goes to the loop and actual work. We got only a wee bit left for stack setup (line 96) and the case of (line 97). At this point, the above makes it clear that if you want to go faster you’ll have to increase the line count and code complexity significantly as you’ll need to replace the two-liner loops with something else, which is bound to be heavier (unrolling, SIMD, etc.)


Rest Under A Tree

Some quick final notes to conclude.

When moving an exception to a procedure, there are two things to keep in mind:

  • the exception will be triggered at another place in the code, to know where it was actually triggered, you’ll have to look up one step in your exception log stack trace… You do have an exception log stack trace in place, don’t you?
  • the compiler won’t “know” about the exception in the called procedure, so it will assume execution continues after your RaiseUnsupported, so you may want to place an Exit after it (which will never be reached), to avoid warnings and allow the occasional register optimization by the compiler.

In the final version, we gained more than the previous profiling run hinted at: the new code allowed the compiler to make better use of the registers. Ofttimes, getting the fat out of the way is all you need to see improvements.

If you check the CPU view, you’ll see everything is quite efficient now, but even then, using all the remaining tricks in the book could probably net noteworthy gains, just at a significant complexity increase. I didn’t try, but I would guess a 2x or 3x speed up should be about right.

If you were to need to go that route, SamplingProfiler could still help you there: on ASM code, you get profiling data down to the ASM instruction… but that’s food for another article.

Eric Tips , , , , , ,

ZJDBGPack re-release

May 4th, 2009

ZJDBGPack is again available, but as an independent download (it used to be bundled with SamplingProfiler).

This is a command-line utility intended for use in a build process or from the Delphi tools menu, whose purpose is to integrate debug information into an executable. The debug information format  is a compressed version of JCL‘s JDBG.

As of know, SamplingProfiler is the only published utility that understands this format, so you can use it either to reduce the size of the executables you deploy for profiling purposes, or if you do not want to deploy directly-readable debug information files.

Eric News , , , , , , ,

SamplingProfiler v1.7.1 bugfix release

April 16th, 2009

SamplingProfiler v1.7.1 is now available, it fixes the crash in the paths dialog reported by Kazan in the forums.

Incidentally this was due to a very old Delphi 5 bit of code that somehow survived Delphi 2009 at the compilation level, but bombed at runtime… I dropped the code and made use of the already existing D2009 version, hence the smaller executable.

For further details on this version, see the v1.7.0 post.

Eric News , , ,

SamplingProfiler 1.7.0 still hot from the compiler

April 15th, 2009

SamplingProfiler v1.7.0 is now available, you can get the zip and release details from its changelog page.

As announced last week, the changes are a fix for a bug that could drastically affect the execution speed of the profiled application when relying on MAP files for debug information, if you were hit by this bug, things should be like night and day with this version (and hopefully I didn’t break anything else in the process…).

The other main addition is that of the real-time monitor, which with default parameters and when activated locally should be reachable at http://localhost:880/ (see the help for other details). The monitor is still at an early stage, and only provides real-time information, as time allows, it may grow to offer more profiling and debug features.SamplingProfiler RealTime MonitorThe current monitor page is a rather basic html page that is fully refreshed periodically, which isn’t very pretty at the moment… an XML version of the real-time information is available at http://localhost:880/sampling.xml, if you come up with a pretty AJAX-based version before I do, feel free to contribute it ;)

Eric News , , , , , , ,