Home > Back-end >  Profiling recursive code in C#/Visual Studio
Profiling recursive code in C#/Visual Studio

Time:03-06

I have some code in C#, using Visual Studio 2019. To simplify, the structure of the code looks like this:

public class Program
{
    private static async Task Main()
    {
        Perft.RunPerft(5);
    }
}

public class Perft
{        
    Board board = new Board();

    public static void RunPerft(int depth)
    {
        if (depth == 0) return 1;

        board.GetAllMoves();

        int _nodes = 0;
        foreach (Move move in board.moves)
        {
            if (board.MakeMove(move))
            {
                _nodes  = PerftRun(depth - 1);
                board.UnmakeMove(move);
            }
        }

        return _nodes;
    }       
}

So I have 3 main functions that I want to know the performance of: GetAllMoves, MakeMove, and UnmakeMove. Is there an easy way to see how much time is spent in each of these functions? Maybe something built in in Visual Studio, instead of using stopwatches?

CodePudding user response:

The Win32 API supports high precision timing using the QueryPerformanceCounter() and QueryPerformanceFrequency() methods.

The first function, QueryPerformanceCounter(), queries the actual value of the high-precision counter at any time.

The second function QueryPerformanceFrequency() returns the count per second of the high precision counter.

In order to get the elapsed time of a code segment, you need to get the actual value of the high precision counter at the two timing moments before the start of the code segment and after the end of the code segment.

The difference between these two values indicates the elapsed time for the code segment to execute. The elapsed time can then be calculated by dividing the difference by the counts per second (high precision timer frequency).

duration = (stop - start) / frequency

Elapsed time = (stop time - start time) / frequency

Main code:

public class HiPerfTimer
{
    [DllImport("Kernel32.dll")]
    private static extern bool QueryPerformanceCounter(
        out long lpPerformanceCount);
    [DllImport("Kernel32.dll")]
    private static extern bool QueryPerformanceFrequency(
        out long lpFrequency);
    private long startTime, stopTime;
    private long freq;
    // Constructor   
    public HiPerfTimer()
    {
        startTime = 0;
        stopTime = 0;
        if (QueryPerformanceFrequency(out freq) == false)
        {
            // High performance counters are not supported
            throw new Win32Exception();
        }
    }
    // start timer
    public void Start()
    {
        // to make the waiting thread work
        Thread.Sleep(0);
        QueryPerformanceCounter(out startTime);
    }
    // stop the timer
    public void Stop()
    {
        QueryPerformanceCounter(out stopTime);
    }
    // Return the timer elapsed time (unit: seconds)
    public double Duration
    {
        get
        {
            return (double)(stopTime - startTime) / (double)freq;
        }
    }
}

Invoke:

HiPerfTimer pt = new HiPerfTimer(); // create a new HiPerfTimer object
pt.Start(); // start the timer
 
Console.WriteLine("Test\n"); // code that needs timing
  
pt.Stop(); // stop the timer
  
Console.WriteLine("Duration: {0} sec\n",pt.Duration); // Print the time of the code that needs to be timed

Namespacs:

using System; 
using System.Runtime.InteropServices; 
using System.ComponentModel;   
using System.Threading;

Demo:

enter image description here

CodePudding user response:

Well, the oldie-but-goody method I would do, and have done many times, is this...

First, wrap a loop around the outer call, so it takes plenty of time, like 10 seconds or more. For example, if you loop it a million times, the number of seconds it takes altogether is the number of microseconds one call takes.

Second, while it is running, manually pause it 10 or 20 times. Each time, record the call stack.

Third, look at the stacks. The fraction of them containing UnmakeMove and each of your other routines is the fraction of time each routine takes. (Roughly. Unless you like decimal places, roughly is usually good enough.) That fraction, divided by the number of times the routine is called, times the number of microseconds of one overall call is the microseconds of that routine.

  • Related