The importance of micro optimizations

by grendel 7. October 2009 07:54

Many years ago when coding in C/C++ or assembler I learned one important rule - DO micro-optimize your code. Unlike macro scale optimization, which should be done after your code is generally working and feature complete, micro optimization should be applied as you go. Why? Because sticking to a few simple rules (which don't affect the overall way in which the code works) as you code is easier than having to fish for the small inefficiencies in your source later on. Some of the optimizations can be performed by the compiler (like taking a constant expression out of loop) but some still depend on the coder doing the Right Thing™.

It seems that, a month ago, I proved that I had forgotten the rules I learned and applied in the past by committing code which affected Mono ASP.NET's performance in a really major way. I'm posting this blog entry as a memento to myself and to others who, like me, might have forgotten that such rules still apply in the 21st century despite all our smart compilers, sophisticated virtual machines and runtimes.

The committed code did (eventually) something like this:

void Method (string s) 
{
	string s2 = GetSomeString ()

	CallMethod (s + '@' + s2);
}

The CallMethod line caused (as we discovered yesterday) a drammatic decrease in MojoPortal's performance - its home page would open on my computer, using local connection in 2.56s (yes, seconds) on average. Gonzalo went hunting for the issue and this morning I read a mail from him pin-pointing (after lots and lots of time wasted on it) the performance loss to that very line. I fixed the issue in our code and suddenly the load time for the page went down to ~107ms (yes, milliseconds)! One might ask whether it was because concatenating two strings and a char is so inefficient? Yes, it is inefficient (as the operation has to convert a char to a string, then allocate and concatenate two more strings) but not enough to justify such performance loss. The key here is the frequency at which the code is being called - GetSection gets called hundreds (if not thousands) of times during one request, and the operation's summed up time contributes to the peformance loss.

This is exactly what I described at the beginning of this post - a micro optimization, a right thing to do in the right place. It can be compared to adding two integer or float variables whose values don't change in a loop which takes thousands of iterations and is invoked by some code very often. The addition is not very expensive if your code performs it once in a while, but in the scenario when it repeatedly calls the code, you will see major loss of performance. The solution is to take the operation outside of the loop. This is precisely what happened here.

So, even in this day and age - ladies and gentlemen, do micro-optimize and pay attention to where your "slightly inefficient" code lives :)

Update:

As Jon suggested below, I should have suggested possible solutions to the issue:

  • CallMethod could take 3 arguments instead of one (depends on what the method does, of course) - that was the solution chosen in this instance to fix the issue as the string concatenation wasn't at all necessary.
  • Using "@" instead of '@' would avoid costly (culture-sensitive) conversion of a char to string

Update:

I'm officially an idiot. The real cause of the slowness was that we've been bypassing the cache because of different key being generated to query cache and another to insert into it. My only excuse - lack of sleep :P (I know, a poor one :D). The post's main point still stands, though - just ignore the rambling about string concatenation. Now, where's my brown paper bag...

Tags:

ASP.NET | General | Mono

Comments (21) -

Barry Kelly
Barry Kelly
10/7/2009 8:41:38 AM #

In order for a char to string conversion and string concatenation (there should only be one String.Concat call) to cost that amount of time, it isn't being called 100s of times, or 1000s of times, it's more like 10,000,000 or more.

Anything that's being called 10 million times or more is going to be slow if it's not optimized. You have to be aware when you're writing code on the critical path like that. But that doesn't mean you should code as if all your code is like that; that way leads to disaster.

Measure first.

Reply

grendel
grendel
10/7/2009 9:36:14 AM #

You're right Barry, but in this case it's proven by practice that this line was the culprit. It's also possible that it's Mono's implementation of string concatenation and char-to-string conversion is suboptimal (it would use culture-sensitive conversion in this case, too, I think).
Also, I didn't suggest you always need to code like that - I merely warned that you need to be aware of such issues in critical parts of your code, read the beginning of the second-to-last paragraph in my post.

Reply

Jonathan Pryor
Jonathan Pryor
10/7/2009 9:24:44 AM #

You showed the problem and described the solution, but you didn't show the solution. Is the fix to use "@" instead of '@'? Change the CallMethod() method to take 3 parameters instead of 1? Something else?  The patch you linked to doesn't make this abundently clear.  

Reply

grendel
grendel
10/7/2009 9:38:41 AM #

The 'fixed the issue' link contains the solution Smile. In this case I opted for adding a third parameter to the method in question and avoided string concatenation and char-to-string conversion completely.

Reply

Seth
Seth
10/7/2009 3:51:36 PM #

where your "slightly inefficient" code lives

IMHO this is article is misrepresenting things a bit.

Obviously, this code (well not the snippet show, but the _relevant_ code!) was grossly ineffecient. Thing is that it is inefficient to any non-trivial op (like the snippet) millions of times over.

Alternatively, you can accept the 'slightly' qualification. In that case, you'd have to drop the 'Micro Optimization' label, though. This is _not_ a micro optimization, as it had _nothing_ whatsoever to do with fixing the snippet function; in fact it had to do with extracting a function from it (replace by parameter), and avoiding the redundant calls to _that_ function.

I know, hairsplitting. I do get the feeling you were trying to say: "see my inefficient string concat caused a slow system". However something like: "my inefficient call flow design caused a slow system" comes closer to the mark. You did _not_ in fact make the concatenation any quicker. (Several strategies depending on threading requirements come to mind...) _That_ would have been a micro optimization pur sang, but unlikely to produce more than doubled performance.

PS. I don't live in Bangladesh. More surprisingly, I don't live in '[Not specified]'. As a matter of fact, I'm not even sure that country is already widely accepted as a sovereign entity by the majority of existing governments?

Reply

grendel
grendel
10/7/2009 5:00:16 PM #

Seth, the point of this article wasn't to show how to do string concatenation right. Neither it was about showing how to design control flow correctly. Also, the code in question had been rendered much slower by including ONLY this concatenation (which just happened to be concatenation, it could have been anything else taking this much time). The point was to show how a seemingly innocent operation can harm your code and how you can improve your code performance by doing the right thing on the micro level (thus micro optimization) - and that was the ONLY point of that post. In other words - the devil is in the detail. And fixing the detail is precisely what micro optimization is, at least in my opinion.

Also, the point of the fix wasn't to make concatenation quicker, but rather to remove the slowdown factor to make the entire code faster (which attempt was successful).

Another thing I attempted to show was how it is not good to always rely on compilers/tools doing the right thing for us.

As for Bangladesh and '[Not specified]' - you might want to let the BlogEngine folks know about this issue Smile

Reply

Sandro
Sandro
10/7/2009 4:30:19 PM #

This is arguably an optimization problem with Mono's JIT. MS.NET optimizes such string concatenation sequences quite well by pre-allocating a string of size s.Length + 1 + s2.Length, then just copying in the data.

Reply

grendel
grendel
10/7/2009 4:42:48 PM #

We suspect it is rather an inefficiency in our globalization code, but haven't managed to investigate it full yet. There's definitely something not right under the hood.

Reply

Keith J. Farmer
Keith J. Farmer
10/8/2009 12:27:47 AM #

I think you need to add this caution:  when given the choice between a micro-optimization and easy-to-maintain code, opt for maintainability.

It is trivially easy for developers (particularly inexperienced developers, but also experienced native developers new to the managed world) to focus their micro-optimizations on entirely the wrong piece of code, when much less effort would be spent doing some restructuring of their algorithm, to much greater effect.  They often feel the urge to micro-manage object lifetimes, connection states, etc even when the best results are to be achieved by touching things as little as possible.

The key, as always, is to decide what "good enough" performance is, and then measure.  There are tools to assist in that effort.  If you meet your metric, optimization is little more than developer masturbation.  If you don't meet your metric, you have legitimate work to do, whether that's determining where the greatest benefit can be obtained, or determining that the metric itself is unreasonable.

The "micro-optimization" I think you intend to refer to is, simply, not writing overly-naive code.

Reply

grendel
grendel
10/8/2009 6:55:04 AM #

You are right. I fell in that trap myself when I first started writing managed code - I used to use native optimization tricks which didn't make sense in the managed world. Measuring should be employed at all times, in our slowness case, though, the decrease was very obvious and the fix obviously made the code much more effective, so measuring wasn't strictly necessary.
And yes, you summed up my intent pretty well in the last paragraph of your comment - thank you for that.

Reply

Andreas
Andreas
10/8/2009 6:00:10 AM #

I wrote/optimized most of the String Methods (including the Concat one that should be used here) and it IS HEAVILY optimized.
If you have a problem with speed then I HIGHLY doubt that it has anything to do with concatenating two strings.
Moreover there is absolutely no globalization involved at at as it is not needed in that case.

Reply

grendel
grendel
10/8/2009 6:52:32 AM #

Andreas, as I wrote in an update, I was being an idiot - the reason for slowness was not the string concatenation.

Reply

Hari
Hari
10/9/2009 2:58:07 AM #

Been there, done that Smile

  anonsvn.mono-project.com/viewvc

Reply

Gigi
Gigi
10/9/2009 3:17:14 PM #

Dude, like in high-school physics class, your common sense should have caught this. If a number is way beyond expectation, something is wrong. On a modern computer, no mater how slow string concatenation could be, it's impossible to go from 100 ms to 2.5 sec for displaying a simple web page. I mean, even if you do a million concatenations, with a million (garbage collected) memory allocations, and you would still finish in let's say 500 ms. But I bet that your page didn't have 1 mil concatenations.

Reply

grendel
grendel
10/9/2009 4:18:33 PM #

Dude, I slept through most of physics classes in high school. And, as I've stated several times in the comments and in the post update - it wasn't string concatenation which was the problem.

Reply

Bubak
Bubak
10/11/2009 1:18:23 PM #

Hi, maybe bother learning some debuging. For example binary search across commits. There is also think called profiler....

Reply

grendel
grendel
10/11/2009 6:57:54 PM #

Hi, thanks for the advice! Just looked up 'debugger' and 'profiler' on Wikipedia - WOW, what a revelation! Thanks again, buddy.

Reply

Dustin M
Dustin M
4/13/2011 1:47:30 AM #

Sleep? You need a better excuse for that. ;)

Reply

Medence
Medence
4/15/2011 10:04:15 AM #

"The real cause of the slowness was that we've been bypassing the cache because of different key being generated to query cache and another to insert into it."

Well, it happens sometimes. But I think we can learn a lot by these cases.

Anyway, thank for the share.

Reply

app maker
app maker
4/16/2011 12:10:42 PM #

Sleep is always my issue as well, but hardly an excuse I think - hey at least you figured out what the problem was, which is half the battle.

Reply

Silverfish
Silverfish
4/20/2011 9:13:52 AM #

Haha, yeah I find that when I do things late at night or when I'm tire I make careless errors as well.

Reply

Add comment

  Country flag

biuquote
  • Comment
  • Preview
Loading

RecentComments

Comment RSS