CODEWITHSUNDEEP
c#asp.netlogginglog4net
Simon at LabSlice-com
Simon at LabSlice-com

Reputation: 3027

Capture username with log4net

I currently write all log4net events to a database, and it seems to work just fine. To capture the logged in user account I use this piece of code:

HttpContext context = HttpContext.Current;
if (context != null && context.User != null && context.User.Identity.IsAuthenticated)
{
    MDC.Set("user", HttpContext.Current.User.Identity.Name);
}

The code seems ok, except for events that have no user context associated with them (ie. a user on our public web page). In that case the log4net capture seems to sometime write the last logged in user account (bad) and sometime write a null (good). Anyone got this feature to work reliably in all cases? I believe I saw a note that MDC is no longer a recommended feature to use, but I wasn't able to find any alternatives that are recommended.

Note: I find it odd that MDC is set with an account name, but never cleared if no user is active. That could be part of the problem. However, I didn't find any MDC code extracts that also clear the username.

Upvotes: 20

Views: 27381

Answers (6)

Gian Marco
Gian Marco

Reputation: 23199

According to Log4Net official API docs, MDC is deprecated:

The MDC is deprecated and has been replaced by the Properties. The current MDC implementation forwards to the ThreadContext.Properties.

Other than that MDC.Set only accept strings as values, so the last solution from @wageoghe cannot work (the one that uses HttpContextUserNameProvider)

My solution has been to use HttpContextUserNameProvider with log4net.GlobalContext, also suggested in official API docs:

  • Add this immediatley after log4net initialization (for example in Global.Application_Start)

    log4net.GlobalContext.Properties["user"] = new HttpContextUserNameProvider();

  • Add this class

    public class HttpContextUserNameProvider
{
    public override string ToString()
    {
        HttpContext context = HttpContext.Current;
        if (context != null && context.User != null && context.User.Identity.IsAuthenticated)
        {
            return context.User.Identity.Name;
        }
        return "";
    }
}

  • Modify log4net configuration by adding the "user" property value, for example:

    <layout type="log4net.Layout.PatternLayout" value="%property{user}"/>

Upvotes: 24

Ben Smith
Ben Smith

Reputation: 20230

As of Log4Net version 1.2.11 you can now simply use the appender pattern to get the authorized user via the ASP .NET request e.g.

%aspnet-request{AUTH_USER}

Upvotes: 11

wageoghe
wageoghe

Reputation: 27608

If the information that is available in the HttpContext is sufficient, that is, if the sample code you posted gives you the right answer (except for the MDC issue) and you would just rather just not write:

HttpContext context = HttpContext.Current; 
if (context != null && context.User != null && context.User.Identity.IsAuthenticated)
{     
  MDC.Set("user", HttpContext.Current.User.Identity.Name); 
}

so often, then you might be able to add the username to your log "automatically" by writing your own custom PatternLayoutConverter for log4net. They are pretty easy to write and you can configure them in your log4net logging configuration just like the built in ones.

See this question for one example of how to write a custom PatternLayoutConverter:

Custom log4net property PatternLayoutConverter (with index)

Using the example at that link, you might be able to do something like this:

namespace Log4NetTest
{
  class HttpContextUserPatternConverter : PatternLayoutConverter
  {
    protected override void Convert(System.IO.TextWriter writer, LoggingEvent loggingEvent)
    {
      string name = "";
      HttpContext context = HttpContext.Current;
      if (context != null && context.User != null && context.User.Identity.IsAuthenticated)
      {
        name = context.User.Identity.Name;
      }
      writer.Write(name);
    }
  }
}

You would configure this in log4net something like this:

  //Log HttpContext.Current.User.Identity.Name
  <layout type="log4net.Layout.PatternLayout">
    <param name="ConversionPattern" value="%d [%t] %-5p [User = %HTTPUser] %m%n"/>
    <converter>
      <name value="HTTPUser" />
      <type value="Log4NetTest.HttpContextUserPatternConverter" />
    </converter>
  </layout>

In addition, you could build other pattern converters that use the Option parameter (see the example at the link above) to pull a specific item from the HttpContext.Current.Items or HttpContext.Current.Session collections.

Something like:

namespace Log4NetTest
{
  class HttpContextSessionPatternConverter : PatternLayoutConverter
  {
    protected override void Convert(System.IO.TextWriter writer, LoggingEvent loggingEvent)
    {
      //Use the value in Option as a key into HttpContext.Current.Session
      string setting = "";

      HttpContext context = HttpContext.Current;
      if (context != null)
      {
        object sessionItem;
        sessionItem = context.Session[Option];
        if (sessionItem != null)
        {
          setting = sessionItem.ToString();
        }
        writer.Write(setting);
      }
    }
  }
}


namespace Log4NetTest
{
  class HttpContextItemPatternConverter : PatternLayoutConverter
  {
    protected override void Convert(System.IO.TextWriter writer, LoggingEvent loggingEvent)
    {
      //Use the value in Option as a key into HttpContext.Current.Session
      string setting = "";

      HttpContext context = HttpContext.Current;
      if (context != null)
      {
        object item;
        item = context.Items[Option];
        if (item != null)
        {
          setting = item.ToString();
        }
        writer.Write(setting);
      }
    }
  }
}

You might also find these links useful:

http://piers7.blogspot.com/2005/12/log4net-context-problems-with-aspnet.html

Here, the blogger proposes a different solution to logging values from HttpContext than what I proposed. Read the blog post to see his description of the problem and for his solution. To summarize the solution, he stores an object in the GlobalDiagnosticContext (the more modern name for MDC). When log4net logs the value of the object it uses ToString(). the Implementation of his object retrieves a value from the HttpContext:

So, you might do something like this:

public class HttpContextUserNameProvider
{
  public override string ToString()
  {
    HttpContext context = HttpContext.Current;  
    if (context != null && context.User != null && context.User.Identity.IsAuthenticated)
    {
      return context.Identity.Name;
    }
    return "";
  }
}

You can put an instance of this object in the GlobalDiagnosticContext (MDC) early in your program and it will always return the right value since it is accessing HttpContext.Current.

MDC.Set("user", new HttpContextUserNameProvider());

This seems a lot easier than what I proposed!

For completeness, if someone wants to know how to do the same thing in NLog, NLog appears to make most/all of the HttpContext information available through its "aspnet-*" LayoutRenderers:

https://github.com/nlog/nlog/wiki/Layout-Renderers

Upvotes: 27

SteveL
SteveL

Reputation: 857

I've used the solution of wageoghe and Gian Marco Gherardi, but rather than GlobalContext have set the thread context immediatley before logging the message:

ThreadContext.Properties["user"] = new HttpContextUserNameProvider();

Upvotes: -2

phillip
phillip

Reputation: 2738

There are two different ways of doing what you want %identity and %username.

Those can be used in your appender pattern.

I've done it before but with unexpected results until I read the following post which cleared it up for me.

See this posting: Log4Net can't find %username property when I name the file in my appender

Upvotes: 2

Tim Lloyd
Tim Lloyd

Reputation: 38444

This is pure speculation, but this sounds very much like it could be an issue related to shared request threads i.e. ThreadPool threads. When you set an MDC value it is associated with the current thread, and that thread will be returned to the ThreadPool at the end of the request and then re-used for subsequent requests. If the value is not overwritten, then you could see old values on new requests.

Consider managing this data in request start and end events, where you can set the username when a request starts, and then clear it on request end. This should give this data the correct lifetime i.e. for the lifetime of the request.

Upvotes: 2

Related Questions