Tracking duration of functions calls in vb.net

问题:

In our VB6 applications, we added a few utility functions for tracking the amount of time spent in a function. We did this to track performance bottlenecks.

Basically, how it worked was there were two utility functions: StartTickCount() and EndTickCount(). You would pass the name of the function in each, and the functions would use a dictionary to get the tick count when StartTickCount() was called, and then subtract the tick count when EndTickCount() was called. This wasn't perfect because it didn't of course take into consideration that calls to get tick count takes time, etc, but basically it worked for our purposes. The pain in the butt part was making sure to call StartTickCount() at the beginning of each function and EndTickCount() at each exit point:

Private Function SomeFuction() as String
    ' indicate the function started
    StartTickCount("MyClass.SomeFunction")


    ' some logic that causes the function to end
    If (some logic) Then
        EndTickCount("MyClass.SomeFunction")
        Return "Hello!"
    End If

    ' final exit point
    EndTickCount("MyClass.SomeFunction")
    Return "World"
End Function

Anyway, is there any functionality built in, either through the VS 2010 debugger or in the System.Reflection namespace, to do something similar in VB.NET?

Basically, what I want is to log the number of times each function is called, the total amount to time spent in that function, the average number of seconds spent in that function, and the maximum amount of time spent in a single call in that function.

I can certainly write this by hand (since we already did once in VB6), but if there are existing tools to make it easier, I'd rather use them.

回答1:

I'd have a look at the stopwatch class - it's designed for this type of thing.

However there is also a fantastic tool out there to do this already and it actually does a better job with very little work. It has a 10-day free trial as well.

http://www.jetbrains.com/profiler/

(I don't work for and am not affiliated with jetbrains - but I wish I was because they make some really cool products)

回答2:

You can achieve the same results by modifying/adapting the following code to your needs:

  'Create a variable for start time:
  Dim TimerStart As DateTime
  TimerStart = Now
 '
 'place your computing here
 '
  Dim TimeSpent As System.TimeSpan
  TimeSpent = Now.Subtract(TimerStart)
  MsgBox(TimeSpent.TotalSeconds & " seconds spent on this task")

You can check documentation about TimeSpan to get directly time in milliseconds or in other formats.

回答3:

It sounds like you need to add some profiling in your application. You may want to start with the beginner's guide to profiling with VS.

You can also add performance counters in your application for runtime metrics. See http://msdn.microsoft.com/en-us/library/w8f5kw2e(v=vs.100).aspx.

For a fuller list of tools and techniques, see http://msdn.microsoft.com/en-us/magazine/hh288073.aspx.

回答4:

I ofently use this helper class. It basically does what @AndreaAntonangeli suggested but arranged to have a cleaner code:

Public Class TimeSpanHelper

    Dim caller_name As String
    Dim timer_start As DateTime
    Dim time_spent As System.TimeSpan
    Dim prev_time As DateTime
    Dim time_diff As System.TimeSpan

    Public Sub New(caller As String)
        caller_name = caller
    End Sub

    Public Sub startClock()
        timer_start = DateTime.Now
        Console.WriteLine(caller_name & " starts at:" & timer_start.ToString)
        prev_time = timer_start
    End Sub

    Public Sub getElapsedTime(Optional flag As String = "")
        time_spent = Now.Subtract(timer_start)
        time_diff = Now.Subtract(prev_time)
        prev_time = DateTime.Now
        Console.WriteLine(caller_name & "-" & flag & " " & time_spent.TotalSeconds & "s from start (" & time_diff.TotalSeconds & "s from previous flag)")
    End Sub

    Public Sub stopClock()
        Dim timer_stop As DateTime = DateTime.Now
        time_spent = Now.Subtract(timer_start)
        time_diff = Now.Subtract(prev_time)
        Console.WriteLine(caller_name & " ends at:" & timer_stop.ToString & " - " & time_spent.TotalSeconds & " seconds elapsed from start (" & time_diff.TotalSeconds & "s from previous flag)")
    End Sub

End Class

Example of use:

'Put this wherever you want to start to count 
Dim timer As TimeSpanHelper = New TimeSpanHelper("MyFunctionName")
timer.startClock()
'Do something ...
timer.getElapsedTime("flag1")
'Do something ...
timer.getElapsedTime("flag2")
'Do something ...
timer.stopClock()

Your output should be something like:

MyFunctionName starts at 30/03/2017 16:57:21
MyFunctionName - flag1 Xs from start (Xs from previous flag)
MyFunctionName - flag2 Xs from start (Xs from previous flag)
MyFunctionName ends at 30/03/2017 16:59:14 - 120s elapsed from start (Xs from previous flag)