1

I have added custom tracing to my app by doing the following inside methods which I would like information about:

public static void MyMethod(params)
{
    pathTrace += "MyMethod(" + params + "){";

    // Some method calls and calculations etc ...

    pathTrace += INTERESTINGOUTPUT + "}";
}

The pathTrace string is then sent to the database once the user journey has ended, containing all the methods I am interested in along with params and output, in a nice readable format.

This seems ugly, however, as I have to add the pathTrace incrementers to every method ...

Can anyone suggest a way that I can write a method which adds this for me (including params and output and brackets if possible), so that I can perhaps call it like this:

public static void MyMethd(params)
{
    pathTrace();

    // Some method calls and calculations etc ...
}

I would ideally like the start and end brackets included (I feel like this is the difficult part) ...

Any advice is much appreciated! Thanks

Bassie
  • 9,529
  • 8
  • 68
  • 159
  • You want to see the Stacktrace? https://msdn.microsoft.com/de-de/library/system.environment.stacktrace%28v=vs.110%29.aspx – Ralf Dec 08 '15 at 12:36
  • Hi Ralf, thanks for your suggestion. I have had a look at Environment.StackTrace, but it provides a lot of details which I am not necessarily interested in. All I need is method names, parameter VALUES and output values - will have another look at the docs as I feel like I may have missed something! – Bassie Dec 08 '15 at 17:19

2 Answers2

1

Two techniques, one that is easy but not elegant, and one that is hard enough that you really need tooling.

Method one: create a timer class that implements IDisposable

public class MyTimer:IDisposable{
     // Start timer in constructor
     // end time in Dispose()
}

This gets timing trace down to one line of code plus curly braces when you use

public void MyMethod(){
   using (MyTimer()){
   //method body
   }
}

Alternatively, you use assembly rewriting, where as a post compile step, a tool looks for methods with attributes and injects additional code. This is Aspect Oriented programming, the various techniques in C# are discussed here.

MatthewMartin
  • 32,326
  • 33
  • 105
  • 164
  • thank you for this insight! Do you know if there is a way of the MyTimer class grabbing the parameter/output values from the method it is surrounding? It would be nice if there was some way of doing this from inside the MyTimer class instead of having to add code to the methods themselves – Bassie Feb 05 '16 at 16:31
  • Nope. C# has params, but nothing like python's kwargs or javascripts arguments array. You can use reflection to get the list of arguments of a method, but you can't get their values at runtime. Ref: https://stackoverflow.com/questions/16201210/does-net-have-an-equivalent-of-kwargs-in-python To do what you're thinking of, you'd have to do code generation (or laboriously write it by hand) – MatthewMartin Feb 05 '16 at 17:15
1

If you called it the way you're asking for, you'd have to examine the stack trace to find the calling method's name and do a lot of reflection to collect runtime argument info, and at substantial cost. You certainly couldn't leave the calls in situ.

You can avoid most of that cost by passing somewhat redundant information (such as the current method name) to your tracing stuff. I've done something similar, so that I can "instrument" the body of a method with a tracing wrapper. Calls might look like:

static void DoSomeMethod( )
{
  Tracer.TraceRun( "DoSomeMethod", ( ) =>
  {
    //--> body of method...
    var x = DoSomeFunction( );

  } );
}

static int DoSomeFunction( )
{
  return Tracer.TraceRun( "DoSomeFunction", ( ) =>
  {

    //--> body of method...
    return 9 - DoSomeFunctionWithArgs( 3 );

  } );
}

static int DoSomeFunctionWithArgs( int arg )
{
  return Tracer.TraceRun( "DoSomeFunctionWithArgs", ( ) =>
  {

    //--> body of method...
    return 1 + arg;

  }, arg );
}

...where the expected output of running DoSomeMethod() would be:

DoSomeMethod(){
 DoSomeFunction(){
  DoSomeFunctionWithArgs(3){
   4}
  5}
 }

To make this work, the Tracer.TraceRun is overloaded, so that I can do methods and functions:

class Tracer
{
  [ThreadStatic]
  private static int depth = 0;
  public static void TraceRun( string name, Action method, params object[ ] args )
  {
    TraceStartCall( name, args );
    depth++;
    method( );
    TraceEndCall( );
    depth--;
  }

  public static T TraceRun<T>( string name, Func<T> function, params object[ ] args )
  {
    TraceStartCall( name, args );
    depth++;
    var results = function( );
    TraceEndCall( results );
    depth--;
    return results;
  }

  private static void TraceStartCall( string functionName, params object[ ] args )
  {
    Trace.WriteLine
    (
      string.Format
      (
        "{0}: {1}{2}({3}){{",
        Thread.CurrentThread.ManagedThreadId,
        new string( ' ', depth ),
        functionName,
        args == null ?
          string.Empty :
          string.Join( ", ", Array.ConvertAll( args, i => i.ToString( ) ).ToArray( ) )
      )
    );
  }

  private static void TraceEndCall( object results = null )
  {
    Trace.WriteLine
    (
      string.Format
      (
        "{0}: {1}{2}}}",
        Thread.CurrentThread.ManagedThreadId,
        new string( ' ', depth ),
        results
      )
    );
  }


}

This code deals with thread-management issues the cheap-and-easy way...by just outputting the threadId so that you can see how your threads interoperate (and marking Tracer's depth with ThreadStatic). The output looked like this when I ran it:

10: DoSomeMethod(){
10:  DoSomeFunction(){
10:   DoSomeFunctionWithArgs(3){
10:    4}
10:   5}
10:  }
Clay
  • 4,999
  • 1
  • 28
  • 45