Weird DirectoryInfo.EnumerateFiles() performance pattern?

Question

I was experimenting with DirectoryInfo.EnumerateFiles() and found this weird performance pattern that I can't understand. If I perform several successive enumerations, each successive enumeration takes longer than the previous one by a substantial amount of time. That is weird. But what's even weirder, it's that if I put several searches in a for loop, then with each iteration, the search times reset. Here's my method and my results:

    static int i;
    static void Main(string[] args)
    {
        for (int j = 0; j < 15; j++)
        {
            var sw = new System.Diagnostics.Stopwatch();

            i = 0;
            sw.Start();
            EnumerateFiles();
            sw.Stop();
            Console.WriteLine(sw.Elapsed.ToString());

            i = 0;
            sw.Start();
            EnumerateFiles();
            sw.Stop();
            Console.WriteLine(sw.Elapsed.ToString());

            i = 0;
            sw.Start();
            EnumerateFiles();
            sw.Stop();
            Console.WriteLine(sw.Elapsed.ToString());

            i = 0;
            sw.Start();
            EnumerateFiles();
            sw.Stop();
            Console.WriteLine(sw.Elapsed.ToString());


            Console.WriteLine("====================================");
        }

        Console.ReadLine();
    }

    private static void EnumerateFiles()
    {
        foreach (var item in new System.IO.DirectoryInfo("d:\\aac").EnumerateFiles("*.*", System.IO.SearchOption.AllDirectories))
        {
            i++;
        }
    }

And the results:

Total files: 5386

00:00:00.2868080
00:00:00.5720745
00:00:00.8443089
00:00:01.1315225
====================================
00:00:00.2729422
00:00:00.5275304
00:00:00.8259863
00:00:01.0712183
====================================
00:00:00.2457264
00:00:00.4642581
00:00:00.6948112
00:00:00.9178203
====================================
00:00:00.2198666
00:00:00.4503493
00:00:00.6717144
00:00:00.8951899
====================================
00:00:00.2391378
00:00:00.4602923
00:00:00.6767395
00:00:00.9082248
====================================
//last one (i == 15):
00:00:00.2138526
00:00:00.4437129
00:00:00.6626495
00:00:00.8794025

Does anyone know why that is happening? Now, the answer to the question about why am I doing four searches in one iteration is: I was trying out some things, measuring the performance and stumbled upon this anomaly, and now I want to know why it is like so.

Answer 1

instead of all the sw.Start();

do sw = System.Diagnostics.Stopwatch.StartNew();

and try again

the issue here is your not resetting the stopwatch, your pausing it

you can also call the sw.Reset(); sw.Start(); or sw.Retart() instead