How to know when an asynchronous call really begins?

Question

I want to be able to measure the time it take to execute an asynchronous method.

When I call the method synchronously, I run the following code and I get the exact amount of time it took a the method MyMethod.

for (int i = 0; i < 5000; i++) {
    stopWatches[i].Start();
    webService.MyMethod(new Request());
    stopWatches[i].Stop();
}

I changed my code to execute MyMethod asynchonously, so now my code looks like this.

var callback = new Action<IAsyncResult>(ar => {
    int i = (int)ar.AsyncState;

    try {
        var response = webService.EndMyMethod(ar);
        stopWatches[i].Stop();
    }
}

for (int i = 0; i < 5000; i++) {
    webService.BeginMyMethod(new Request(), new AsyncCallback(callback), i);
    stopWatches[i].Start();
}

The problem is that the stopwatches don't measure the time required to execute a request anymore. They measure the time from when a request entered in the ThreadPool queue until the end of the call. So I end up with a list of stopwatches with a time going up linearly.

How do I fix my stopwatches? Is there a way to know exactly when the request start?

Thanks!

UPDATE: I cannot change the implementation of MyMethod.

Answer 1

What exactly are you trying to do with the measurements? As is, you are measuring the actual amount of time it takes from when you request some work be done to when it is completed. That seems to make sense. Both before and after your code switch you are measuring the actual request latency.

Answer 2

What this sounds like you're trying to do is setup an aspect around the mymethod class. The easiest way to do this would be with an AOP framework like PostSharp. That you create something along the lines of

public class MyStopWatchContext
{
    Stopwatch _watch = new Stopwatch();

    public void OnMethodEntry()
    {
        _watch.Start();
    }

    public void OnMethodExit()
    {
        _watch.End();
        Debug.Print(_watch.Duration);
    }
}

Then inside your class with your method you have

public class MyService
{
    [MyStopWatchContext]
    public void SomeServiceMethod()
    { ...
    }
}

This would allow you tie that aspect to the method without needing to modify the method. However you will still need to be able to recompile the code there. So this should be viable even if that class is just a proxy to an external service you have no control over since you should be able to just sit that aspect ontop of the proxied call.

Answer 3

Create a method BeginTimedMyMethod, not in the webservice class. In the implementation of BeginTimedMyMethod, call an intermediate method instead of MyMethod that is called asynchronously. Start the stopwatch there, then call MyMethod.

void BeginTimedMyMethod(...)
{
    //create delegate with StartMethod as target
    //Invoke StartMethod delegate
}

void StartTimedMethod(Request request)
{
    stopWatches[i].Start();
    webservice.MyMethod(request);
}