How to assign unique id to the request and use it in logging

Topics: Web Api
Dec 1, 2011 at 9:14 AM

When request comes in I would like to assign unique id to it. The idea is to use this id when logging though the whole pipeline (request handles, error handlers, actual operation).

In my current implementation I just create the id when instance of my service is created. This is WebApiConfiguration.CreateInstance method. The problem is that I do some validation using request handlers and I also have error handler for exception. Those places do not see this request specific id. Also if the validation in my request handler throws exception the execution goes directly into error handler.

So I should probably create the unique id in message handler (inherit from DelegatingHandler) but I don't know what is the best practice for it and how I can access that id in my service and in the request and error handlers.

Dec 1, 2011 at 12:07 PM

I have the exact same problem :) At first we put it into the HttpContext, and then access HttpContext.Current.Items from the error logger (in our case log4net configuration), but this doesn't work when hosting the REST framework in anything else than ASP/IIS, so no self hosting.

Our current thinking is to create the request id (GUID in our case) in a delegating handler and put it into the HttpRequest.Properties collection.  After that it can be read from that collection, and in the API classes we will pass this collection on to our BLL/DAL classes.
However.. we still have a problem on how to access this (and other request-bound data) from external classes, like log4net.

Dec 1, 2011 at 1:02 PM

Hi

I had the same problem, and solved it the following way.....

we're using log4net, and here you can set properties on the thread context, using:

ThreadContext.Properties[name] = value;

and refer to this property value in the pattern used for logging.

The values of the property I set in a DelegatingHandler, based on some info send by the client..... you could just generate an id and use it as identifier.....

Søren

 

 

Dec 1, 2011 at 1:37 PM

I've always assumed that log4net usually runs on a different thread than you would run the code you showed?

Dec 2, 2011 at 4:02 PM

I wrote a blog post describing the solution I'm using. It uses log4net but same idea can be used with other logging frameworks. I'm using the same solution with Azure. I would appreciate any input you can give to improve the solution.

http://catchblock.com/blog/post/2011/12/02/WCF-Web-API-and-logging-unique-request-id-with-log4net.aspx

Dec 2, 2011 at 4:21 PM

Excellent blog post :) Just one question, why store the requestId in a HTTP header but not the HttpRequestMessage.Properties collection?

Coordinator
Dec 2, 2011 at 4:21 PM

Coll stuff tparvi. I posted a comment with a few suggestions.

Dec 2, 2011 at 4:42 PM
SiggiG wrote:

Excellent blog post :) Just one question, why store the requestId in a HTTP header but not the HttpRequestMessage.Properties collection?

I couldn't get it to work. Just to be clear here is what I tried.

When I create the Id I put it into HttpRequestMessage.Properties

        public static void InsertUniqueIdIntoRequest(HttpRequestMessage request)
        {
            request.Properties[RequestIdKey] = GenerateRequestId();
        }

Now when I need to access the request id the I use the following code

        public static string GetUniqueIdFromCurrentRequest()
        {
            var current = OperationContext.Current;
            if (null == current)
            {
                return null;
            }

            var value = current.IncomingMessageProperties[RequestIdKey].ToString();
            return value;
        }

The problem is that the IncomingMessageProperties does not contain my value. Where should that value be? I tried to look for it in the debugger but couldn't find it from the OperationContext.Current

Dec 2, 2011 at 5:04 PM
Edited Dec 2, 2011 at 5:05 PM

Ahh hmm.. I thought the "httpRequest" item in IncomingMessageProperties was of type HttpRequestMessage, not HttpRequestMessageProperty.  I wonder if you can access that object from somewhere?

If so, you could do:
return httpRequest.Properties[RequestIdKey].ToString();

 

Glenn, can you access that from somewhere like the OperationContext? (We basically need a globally-accessible HttpRequestMessage instance :) ).

Dec 2, 2011 at 5:41 PM

I investigated this a bit more and this is what I found. I don't know if this is a bug or just something I don't completely understand.

I add my own request id into HttpRequestMessage.Properties collection. This happens in the MessageHandler (inherited from DelegatingHandler). I can see that there are already other values. In the debugger I'm using the "Make object id" to tag few of them. After adding my request id into the collection there are 7 key-value pairs.

Now inside my service method I look into OperationContext.Current.IncomingMessageProperties I can see that some of the objects I tagged are there but the one I added is not.

There is also good news. I found my request id. It is here: OperationContext.Current.IncomingMessgeProperties. There is a value which has type Microsoft.ApplicationServer.Http.Dispatcher.OperationHandlerPipelineContext. There is non public member pipelineValues which contain two objects of type HttpRequestMessage and both of them contain my request id. So it has not been lost :)

Coordinator
Dec 2, 2011 at 6:56 PM

Don't use OperationContext.Current, it will not work properly. Incoming message properties are different. You need to take in HttpRequestMessage / HttpRequestMessage<T> on your operation as param. Then you can access the request and the properties.

Dec 3, 2011 at 6:08 AM

How do I access the current request inside my error handler? I would like to write the error into log file and associate that line with the request id. Otherwise I have no idea for which request this error belongs to. Can I use HttpContext.Current to store the request id and then access it inside error handler?

 

Coordinator
Dec 3, 2011 at 9:08 AM

tparvi you should make your error handler derive from HttpErrorHandler. It will pass you the HttpRequestMessage so you can access it. 

Glenn

Dec 3, 2011 at 12:15 PM
gblock wrote:

tparvi you should make your error handler derive from HttpErrorHandler. It will pass you the HttpRequestMessage so you can access it. 

Glenn

It will only pass the exception and HttpResponseMessage:

public bool TryProvideResponse(Exception error, ref HttpResponseMessage message)

That's why I used OperationContext.Current or HttpContext to store the request id. I couldn't figure out other way to access the request inside my error handler.



Coordinator
Dec 3, 2011 at 3:59 PM
Put the id in the request properties.

Sent from my Windows Phone

From: tparvi
Sent: 12/3/2011 5:15 AM
To: Glenn Block
Subject: Re: How to assign unique id to the request and use it in logging [wcf:281421]

From: tparvi

gblock wrote:

tparvi you should make your error handler derive from HttpErrorHandler. It will pass you the HttpRequestMessage so you can access it.

Glenn

It will only pass the exception and HttpResponseMessage:

public bool TryProvideResponse(Exception error, ref HttpResponseMessage message)

That's why I used OperationContext.Current or HttpContext to store the request id. I couldn't figure out other way to access the request inside my error handler.



Jan 11, 2012 at 1:38 PM

Running into the same problems as above.  Is there any way to access the HttpRequestMessage from an error handler?

Jan 11, 2012 at 6:16 PM

You probably answered this yourself in the other thread we've been communicating on ..but.one of the ways would be to use IncomingMessageProperties["httpRequest"].ToHttpRequestMessage. I haven't tried this but HttpResponseMessage also has a RequestMessage property that might be set on the incoming parameter.

Coordinator
Jan 11, 2012 at 6:48 PM

SiggiG if you are using HttpErrorHandler it exposes the request messages.

Jan 11, 2012 at 9:19 PM
gblock wrote:

SiggiG if you are using HttpErrorHandler it exposes the request messages.

How? there is not property on the base class and the parameter into the method is a HttpResponseMessage, not request :)

Coordinator
Jan 11, 2012 at 9:20 PM
Response has a Request property hanging off of it.

From: SiggiG [notifications@codeplex.com]
Sent: Wednesday, January 11, 2012 2:19 PM
To: Glenn Block
Subject: Re: How to assign unique id to the request and use it in logging [wcf:281421]

From: SiggiG

gblock wrote:

SiggiG if you are using HttpErrorHandler it exposes the request messages.

How? there is not property on the base class and the parameter into the method is a HttpResponseMessage, not request :)

Jan 12, 2012 at 8:20 AM
Edited Jan 12, 2012 at 8:26 AM

Sorry Glenn, must have been very tired last night :)  But the reason for my confusion is in my tests the HttpResponseMessage is always null.  I just tried throwing a normal exception, HttpResponseException and HttpRequestException and in all cases the param is null. 
I seem to remember the message parameter was more used to return a response from the handler, but not actual input?
Edit: The WebAPI docs actually state: "The error handler can handle the exception by creating a new HttpResponseMessage and assigning it to the message parameter."

Am I misunderstanding something here? Is there a way to get the framework to send the message as an input param to the method?

Jan 20, 2012 at 9:24 AM

I've hit this as well... I can't see an easy way of getting the HttpRequestMessage from an error handler.

Jan 20, 2012 at 3:37 PM

In the error handler try this:

            if (exception is HttpResponseException)
            {
((HttpResponseException)exception).Response.RequestMessage
}

Jan 20, 2012 at 3:40 PM

I know that won't get you it all the time... but if its an error you throw it will be :/

I see no other way to get to the current response OR message.

 

, ref HttpResponseMessage message is always null

Jan 20, 2012 at 3:41 PM

Also try:

 

System.ServiceModel.Web.WebOperationContext.Current

Jan 20, 2012 at 5:06 PM

I've been using the following inside HttpErrorHandler to get the request (ToHttpRequestMessage is extension method in WCF Web API).

var request = OperationContext.Current.RequestContext.RequestMessage.ToHttpRequestMessage();

There are some cases where OperationContext.Current might be null. E.g. if you are doing some validation using HttpOperationHandlers. Now if you throw exception from that handler it might be that the OperationContext.Current is null when you are processing the exception in the HttpErrorHandler. I'm not 100% sure of this.

One way to handle this is to wrap your method into try catch and then just throw new exception like this:

public HttpResponseMessage CreateAccount(HttpRequestMessage<Account> request)
{
	try
	{
		// Handle the request
	}
	catch(Exception exp)
	{
		// What ever exception you get throw HttpResponseException
		// and inject the request into it. This way HttpErrorHandler
		// knowns the request this exception belongs to
		throw new HttpResponseException(request, exp);
	}
}

I'm not sure how good idea that is and I haven't used it myself.