Method-tracing with EntLib 5.0

Topics: Logging Application Block
Jun 20, 2011 at 10:59 PM

Helo,

I would like to add some method-tracing to my webservice-methods, but don't know exactly how to get the things I want.

Short summary of the log:

  • Single line in textfile
  • Fixed delimiter between the items
  • "START" or "END" at the beginning of the line
  • A timestamp
  • The methodname
  • The parameters send to the method

For example:
START | timestamp | methodname | param1: value1 | param2: value2 | param3: value3

I've been reading about the TraceManager and this might do the trick if it's possible to create the logmessage as described above,
this means a different one for the start and the end-trace.
Or should I write my own custom tracelistener (with custom logFormatter) and do some logging at the beginning and the end of each method?

Thanks in advance.

Jun 21, 2011 at 7:21 AM
Edited Jun 21, 2011 at 7:29 AM

Hi,

Yes, your idea is correct. You need to create a custom trace listener to pass the method name and the parameters to your custom LogFormatter. Though, you can also use the TraceManager with your custom tracelistener (which I find convenient) so that you won't have to call the LogWriter.Write() before and after each method call.

 

Noel Angelo Bolasoc
Global Technologies and Solutions
Avanade, Inc.
entlib.support@avanade.com

Jun 21, 2011 at 7:42 PM

Thank you for the information.

I'll take a look at it and give it a try.

Jun 21, 2011 at 10:07 PM
Edited Jun 21, 2011 at 10:08 PM

Hello Noel,

I guess I'm a bit confused with the "normal" logging of the EntLib I use for my exception shielding and the things I want to do.
I've created my custom tracelistener and logformatter and added the tracemanager in my method.
In the config I've added a category "MethodTracing" with "MyTraceListener" as Listener.
In "MyTraceListener" I've added "MyTraceFormatter" as Formatter.

But at this moment I'm a bit stuck:

  1. I don't know how to pass the methodname and parameters to the listener/formatter
    Do I somehow have to use the "Attributes" from the config for that?
  2. I can't specify a rolling flatfile to the listener.
    Or do I have to write my own logic for that in the custom TraceListener Write-methods?
  3. In my formatter I have for now put the word "START" hardcoded into the StringBuilder.
    Is there a way to specify one way or the other that it's about the start of the trace or the end of the trace?

As far as I can tell,  all I have right now is that a tracemanager is started with a category assigned to it, but it won't do anything.

I know it's a lot I'm asking, but I really appreciate the help.

[ConfigurationElementType(typeof(CustomTraceListenerData))]
public class MyTraceListener : CustomTraceListener
{

	public override void TraceData(TraceEventCache eventCache, string
			source, TraceEventType eventType, int id, object data)
	{
		if (data is LogEntry && Formatter != null)
		{
			WriteLine(Formatter.Format(data as LogEntry));
		}
		else
		{
			WriteLine(data.ToString());
		}
	}
		
	public override void Write(string message)
	{
		WriteLine(message);
	}

	public override void WriteLine(string message)
	{
		WriteLine(message);
	}
}
[ConfigurationElementType(typeof(CustomFormatterData))]
public class MyTraceFormatter : ILogFormatter
{
	public string Format(LogEntry log)
	{
		var sb = new StringBuilder();
		sb.Append("START ** ");
		sb.Append("Methodname: ");

		sb.Append(log.ExtendedProperties.ContainsKey("Methodname")
		          	? log.ExtendedProperties["Methodname"].ToString()
		          	: "<unknown>");

		foreach (var property in log.ExtendedProperties.Keys)
		{
			if (property =="Methodname" )
				continue;
			sb.AppendFormat(" ** {0}: {1}", property, log.ExtendedProperties[property]);
		}

		return sb.ToString();
	}
}
//This is a method in my webservice	
public IEnumerable<Table1> GetAllTable()
{
	TraceManager traceManager = EnterpriseLibraryContainer.Current.GetInstance<TraceManager>();
	using (traceManager.StartTrace("MethodTracing"))
	{
		return _queryHandler.GetAllTable();			
	}
}
Jun 22, 2011 at 5:04 AM
Edited Jun 22, 2011 at 5:10 AM

Hi,

My apologies but I thought this would be easy. I've just realized the challenge on passing the method and parameter name :). This includes customizing the Tracer class itself specially the WriteTraceMessage method. On the other, I also realized that invoking the LogWriter.Write before and after the method call is not the best approach since you have to manually supply the method name and parameters. The best approach is to use the Policy Injection Application Block to intercept each method call and create a custom handler to do the logging. Your custom handler's Invoke method may look like this:

 
public IMethodReturn Invoke(IMethodInvocation input,
                                     GetNextHandlerDelegate getNext)
        {

            //Log Before the Method Call
             Logger.Write("START | {timestamp} | {methodname} | {param1}: {value1} | {param2}: {value2} | {param3}: {value3}", "General");
             
             IMethodReturn msg = getNext()(input, getNext);
             
            //Log After the Method Call
             Logger.Write("END | {timestamp} | {methodname} | {param1}: {value1} | {param2}: {value2} | {param3}: {value3}", "General");
             
            return msg;
        }
 
Some notes to consider:
1) Add reference to Microsoft.Practices.Unity.Interception and System.Configuration for the custom handler to compile.
2) The custom handler should have a constructor that accepts a NameValueCollection object.
3) The class used for policy injection should inherit from MarshalByRefObject
4) You may use the Assembly Matching Rule so that all the methods will be intercepted.
5) For less work, you may not create a custom log formatter. In my code above, I just used the default formatter with just the {message} token.
6) You can use the input.MethodBase.Name to get the name of method, input.Arguments.GetParameterInfo(index).Name to get the parameter name and input.Arguments[index] to get the parameter value.
Let me know if you have further questions :)
 
 
Noel Angelo Bolasoc
Global Technologies and Solutions
Avanade, Inc.
entlib.support@avanade.com
Jun 22, 2011 at 9:05 PM

Looks like I have a lot of reading to do first. I was hoping that it would be a little bit easier too :-)

I'll give it a try one of the next days.

Thank you for the help and I will probably get back with some questions :-)