Shiraz Bhaiji
Shiraz Bhaiji

Reputation: 65461

Correctness of .net stopwatch

We are debugging some performace problems and have notice some strange results from stopwatch.

  1. We have a client that calls a web service
  2. We log the time at the service layer og the web service with stop watch
  3. We log the time at the lower layer with datetime.now.ticks

Layer 2 is just a pass through layer with 2 lines of logging.

The times recorded are:

  1. 110 ms
  2. 52125 ms
  3. 125 ms

We had expected 2 to be less than 1, although no api is accurate to 1 ms.

We create a new stopwatch in each service call so this is not the time of an old stopwatch thar has been restarted.

Anyone know why we are getting these figures?

Edit

2 and 3 are on the same machine and the same app domain

The stopwatch code is:

            var sw = new Stopwatch();
            sw.Start();

            //code to call layer 3

            sw.Stop();
            orchestrationContext.LogOperationTime(functionName, sw.ElapsedMilliseconds);

logging of time in layer 3

    protected DateTime StartTime { get; set; }
    StartTime = DateTime.Now;

    // code 

    new TimeSpan(DateTime.Now.Ticks - StartTime.Ticks).Milliseconds

The logging of 1 is on a seperate machine, logging using Websphere.

Upvotes: 0

Views: 634

Answers (2)

Jodrell
Jodrell

Reputation: 35746

Okay, your second code sample should be returning TimeSpan.TotalMilliseconds, using just Milliseconds you will get the sub second part.

Why aren't you using a StopWatch in the layer 3 code, in the same style as your layer 2 code, it is more accurate?

Your question title is "Correctness of StopWatch" but it seems you are comparing bananas with peaches and apples. StopWatch will use a HighResolution timer if supported by your hardware or operating system otherwise it will fallback to a System.Timer which offers a granularity of around 15ms.

I can't comment on how or whether to use WebSphere but it will not offer more accurate timing than StopWatch unless it uses an API to some other high accuracy time source.

Upvotes: 3

Emond
Emond

Reputation: 50692

As I guessed:

new TimeSpan(DateTime.Now.Ticks - StartTime.Ticks).TotalMilliseconds 

TotalMilliseconds gets the timespan in milliseconds

Millisecond gets the millisecond part of the timespan

Upvotes: 1

Related Questions