Logging only top-most ThreadContext stack item

Question

We're using Log4net's ThreadContext.Stacks and it is mostly working well. My problem comes if there have been multiple ThreadContext.Stacks["key"].Push(...).

With a simple ConversionPattern:

<param name="ConversionPattern value="... topProp=%properties{key} ..."/>

I see log entries like:

... topProp=first second third ...

I'd really like to see only the most recently pushed value rather than all the values. I had hoped I could put something like the following in my appender/layout/ConversionPattern:

<param name="ConversionPattern value="... topProp=%properties{key}{1} ..."/>

but that doesn't work. I can kludge it by assuming/requiring all values to be the same length (say 5) and doing:

<param name="ConversionPattern value="... topProp=%5.5properties{key} ..."/>

But that isn't real attractive. Any ideas?

Thanks!

[Edit to add very simple example]

using System;
using System.IO;
using log4net;
using log4net.Config;

namespace ThreadLocalExample {
class Program {
    private const string PropJobId = "Example:JobId";

    static void Main() {
        XmlConfigurator.Configure(new FileInfo("log4net.cfg"));
        var log = LogManager.GetLogger(typeof(Program));

        ThreadContext.Stacks[PropJobId].Push("Old");

        log.Debug("Enter using");
        using (ThreadContext.Stacks[PropJobId].Push("New")) {
            log.Debug("stuff");
        }
        log.Debug("Out of using");

        log.Debug("done.");
        Console.ReadKey();
    }
  }
}

With the log4net configuration:

<appender name="Console" type="log4net.Appender.ConsoleAppender">
    <threshold value="ALL" />
    <layout type="log4net.Layout.PatternLayout">
        <param name="ConversionPattern" value="[jobId=%P{Example:JobId}]: %m%n" />
    </layout>
</appender>

Produces:

[jobId=Old]: Enter using
[jobId=Old New]: stuff
[jobId=Old]: Out of using
[jobId=Old]: done.

But I'd like:

[jobId=Old]: Enter using
[jobId=New]: stuff
[jobId=Old]: Out of using
[jobId=Old]: done.

Answer 1

I had the same problem, and it was not only about 'bad formatting', because I used database appender (AdoNetAppender) which expects integers. So after joining all stacked values together the result is not an integer any more. Consider an appender like this:

<appender name="DbAppender" type="log4net.Appender.AdoNetAppender">
...
<commandText value="INSERT INTO Log ([Id]) VALUES (@Id)" />
<parameter>
    <parameterName value="@Id" />
    <dbType value="Int32" />
    <layout type="log4net.Layout.PatternLayout" value="%P{someId}" />
</parameter>

This appender will not accept any log message, where 'someId' is stacked twice or more - no logs in database ...

So, to solve this problem I gave up with stacks and turned back to flat properties. I've coded some short extension:

    public static class Log4NetExt {
        public static IDisposable ThreadContextPush(string key, object value) {
            object oldVal = ThreadContext.Properties[key];
            ThreadContext.Properties[key] = value;
            var topMostCleaner = new DispCleaner();
            topMostCleaner.EvDispose += () => {
                // Pop = restore old value
                ThreadContext.Properties[key] = oldVal;
            };
            return topMostCleaner;
        }

        private class DispCleaner : IDisposable {
            public event Action EvDispose;

            public void Dispose() {
                if (EvDispose != null) EvDispose();
            }
        }
    }

And now, instead of:

using (ThreadContext.Stacks[PropJobId].Push("New")) {

write:

using (Log4NetExt.ThreadContextPush(PropJobId, "New")) {

and it works ok ;)

(This short code does not follow all best practises of building disposable objects, deleting event handlers and all this stuff, but it is short and I think it is safe in this simple case).

Answer 2

I have Done it via Filip solution modified as

 public static class Log4NetExt
    {
        public static IDisposable ThreadContextSet(string key, object value)
        {
            //object oldVal = ThreadContext.Properties[key];
            ThreadContext.Properties[key] = value;
            var topMostCleaner = new DispCleaner();
            topMostCleaner.EvDispose += () => {
                // Pop = restore old value
                //ThreadContext.Properties[key] = oldVal;
                ThreadContext.Properties[key] = null;
            };
            return topMostCleaner;
        }

        private class DispCleaner : IDisposable
        {
            public event Action EvDispose;

            public void Dispose()
            {
                if (EvDispose != null)
                {
                    EvDispose();
                }
            }
        }
    }

And used it like

using (Log4NetExt.ThreadContextSet("ContextId", "Feed")) using (Log4NetExt.ThreadContextPush("ContextValue", objFeed.FeedId)) {

}