C# Performance weird case

Question

I was testing some cases in C# to consider some essentials in performance, While i was testing i faced a weird case

 for (int i = 0; i < 30; i++)
 {
     DateTime d = DateTime.Now;
     print();
     result.Add  ((DateTime.Now - d));
 }

 foreach(TimeSpan t in result)
     Console.WriteLine(t.ToString());

while the print function was simply :

public static void print ()
{
     for (int i = 0; i < 10000; i++)
     {
         Console.WriteLine( string.Format("{0}", i));       
     }
}

i was shocked with the results while the first three loops it took about 5 seconds while after that it took about 0.5 sec. Here is some :

00:00:05.6212696
00:00:05.6072002
00:00:05.5837965
00:00:01.9451673
00:00:00.5526335
00:00:00.5540554
00:00:00.5676418
00:00:00.5372442
00:00:00.5772550

i just want to know why it got better by almost 10 times after the third iteration?

Is this problem reproduce-able? When I tested I got results between 0.81 and 1.14 seconds. — Salman A, Feb 22 '12 at 08:49
yes Mr. @GazTheDestroyer and Mr. Salaman A it seems like as Tigran said it can vary from PC to PC — Hilmi, Feb 22 '12 at 10:25
What you're measuring is the performance of `Console.WriteLine`. What that does depends on whether the console is visible. — Mike Dunlavey, Feb 22 '12 at 15:54

score 8 · Answer 1 · answered Feb 22 '12 at 08:15

8

Your bottleneck here is going to be Console.WriteLine. Various things could affect that, but in particular if you minimized the window or something similar, that could massively speed things up.

Are you sure you're really measuring anything useful? Does your real world application do a lot of writing to the console?

Note that it's generally better to use Stopwatch than DateTime.Now for measuring performance, although it wouldn't make much of a difference here.

answered Feb 22 '12 at 08:15

Jon Skeet

1,421,763
867
9,128
9,194

Thanks alot my friend, you have a point in general but i think that my point was that it got faster, how the 'Console.WriteLine' gets berret or something ? – Hilmi Feb 22 '12 at 08:27
I tested with minimising the console window halfway through, but that did not nearly cause the speedup that user1225246 got. Dropping from around 1.6 seconds to 1.1. – Mr Lister Feb 22 '12 at 08:53
@user1225246: Well did you cover up the console window or anything like that? Or perhaps the graphics subsystem started using acceleration or something like that. Basically, unless you're *really* interested in measuring the speed of console output, these numbers are useless. – Jon Skeet Feb 22 '12 at 08:57
Debug.WriteLine is probably more appropriate anyway. Plus a quick search of SO has several articles that indicate it's "faster" or at least more consistent e.g. http://stackoverflow.com/questions/5272177/console-writeline-slow – dash Feb 22 '12 at 09:01
1

@dash: It entirely depends on what you're trying to do. For logging, I'd rather use a dedicated logging package like Log4net. – Jon Skeet Feb 22 '12 at 09:05
@JonSkeet Totally agree, but it's always tempting to just throw in some Debug.WriteLine statements in a small test app like this. I like these kind of questions, it's fun to get ILSpy out and dig around under the hood, but, most of the time, they'd just be lines in a log4net file ;-) – dash Feb 22 '12 at 09:11

score 3 · Accepted Answer · answered Feb 22 '12 at 08:41

I just run the same code in my PC and got the following output:

00:00:00.0469083
00:00:00.0312722
00:00:00.0312722
00:00:00.0469083
00:00:00.0312722
00:00:00.0312722
00:00:00.0312722
00:00:00.0469083

....

As you see there is no notable difference. I would suggest, first do not loose the time on checking the performance for these kind of cases, as it can vary from PC to PC, and repeat suggession of Jon, to use StopWatch, for more accurate measurment.

C# Performance weird case

2 Answers2