Nlog: MDLC implementation uses mutable dictionary which causes reference updates between threads

Created on 29 Sep 2015 · 33Comments · Source: NLog/NLog

The MDLC implementation MappedDiagnosticsLogicalContext.cs uses a mutable dictionary which causes reference updates between threads since CallContext uses shallow copy when flagged as write on copy during thread/task delegation. It basically means that an update of a value in a child thread will also update the value in the parent thread, which should not be the expected behavior.

You should consider using a immutable dictionary. Or why not use the CallContext directly by prefixing the items with the dictionary key? That will be more effective than recreating a dictionary every time a change needs to occur.

I refer to the great CallContext post created by Mr Cleary explaining this even further. http://blog.stephencleary.com/2013/04/implicit-async-context-asynclocal.html

Also, allowing object types to be inserted is a potential problem since CallContext.LogicalSetData requires the data to be marked as Serializable or it will throw an exception. See parameters description at https://msdn.microsoft.com/en-us/library/system.runtime.remoting.messaging.callcontext.logicalsetdata(v=vs.110).aspx

I give you an example of how you con simplify the implementation and get rid of the above problems. It lacks the Contains, Remove and Clear methods but they should be fairly simple to implement.

``` c#
public static class LogicalThreadContext
{
private const string KeyPrefix = "NLog.LogicalThreadContext";

private static string GetCallContextKey(string key)
{
    return string.Format("{0}.{1}", KeyPrefix, key);
}

private static string GetCallContextValue(string key)
{
    return CallContext.LogicalGetData(GetCallContextKey(key)) as string ?? string.Empty;
}

private static void SetCallContextValue(string key, string value)
{
    CallContext.LogicalSetData(GetCallContextKey(key), value);         
}

public static string Get(string item)
{
    return GetCallContextValue(item);
}

public static string Get(string item, IFormatProvider formatProvider)
{
    if ((formatProvider == null) && (LogManager.Configuration != null))
    {
        formatProvider = LogManager.Configuration.DefaultCultureInfo;
    }

    return string.Format(formatProvider, "{0}", GetCallContextValue(item));
}

public static void Set(string item, string value)
{
    SetCallContextValue(item, value);
}

}
```

bug

Source

Fresa

👍1

All 33 comments

Thanks for detailed explanation and example! I will take care of.

By the way, we think that MDC/GDC/MDLC things needs to improvement.
If you're interested in it, could you take a look at #886

I belive you will make perfect suggestions.

UgurAldanmaz on 29 Sep 2015

@BrutalCode I am working on #886. I will see if I can get this done in that itself.

s-sreenath on 22 Oct 2015

Thank you @Page-Not-Found.
Do you mean that your workings on #886 will also fix this issue?

UgurAldanmaz on 23 Oct 2015

While working on #886 I hit the same issue during testing. Can you take a look at this comment, I am new to OSS development.

https://github.com/NLog/NLog/issues/886#issuecomment-150395967

s-sreenath on 23 Oct 2015

It is great thing that you hit the same issue during your tests. So that you can identify and solve the problem.

I will look your comment. I am at work now and not comfortable to do this.

By the way, do not worry, I am new too :)

UgurAldanmaz on 23 Oct 2015

OSS FTW!

When I found time, I will look at it :)

304NotModified on 23 Oct 2015

Hi @Page-Not-Found
What is final situation of your working on #886 ? Can it fix also this issue?

UgurAldanmaz on 16 Nov 2015

@UgurAldanmaz

GDC and MDC is done (needs last review), MDLC isn't (failed), so no. But we really need a new MDLC in #886

304NotModified on 16 Nov 2015

Thank you @304NotModified I was little busy recently. I will try to write new MDLC.

What is our plan to release next NLog version which needed MDLC?

UgurAldanmaz on 16 Nov 2015

just a 4.x release. So if we can fix the new GDC and MDC (with new names, see #886), and then the new MDLC (need also new name), then I will merge it into 4.3 or 4.4

304NotModified on 16 Nov 2015

https://github.com/NLog/NLog/pull/1060 has been merged to branch "Overhaul-contexts".

304NotModified on 3 Dec 2015

So we are ready to work on MDLC? We discussed and planned here

UgurAldanmaz on 3 Dec 2015

Yes we can start :)

304NotModified on 3 Dec 2015

@UgurAldanmaz thanks for thinking with us :)

So who will do? I guess I have interfered by mistake in the last discussion :)
However, it seems that I will do based on what we talked at here :) (I'm already assigned :)

UgurAldanmaz on 3 Dec 2015

Let's chat on gitter for that :)

304NotModified on 3 Dec 2015

Hi @Fresa.
I searched for a solution. It is a really difficult stuff. I need to more info about what we need to achive. Could you give a more info also an application/use case example?

UgurAldanmaz on 21 Dec 2015

Take a look at the example I provided in my initial post. That's all you need to securely read and write to the call context since a string is immutable. It also removes the problem with accidentally send non-serializable objects, since a string always is serializable ;) "Name spacing" the key by using a prefix gets rid of potential problems that someone else uses the same key since the call context is globally available.

Fresa on 4 Jan 2016

As far as I understand we like to have:

Updates set in parent should be visible in childs
Updates in childs should be only visible in the child who has updated it
Updates in childs should not be visisble to the parent.

@Fresa, Is this I correct?

Also, allowing object types to be inserted is a potential problem since CallContext.LogicalSetData requires the data to be marked as Serializable or it will throw an exception.

I think that's the responsibility of the user. We should have to document that well.

304NotModified on 4 Jan 2016

Thanks for reply @Fresa!

We need to store object values as well as string. So we cannot use string here.

UgurAldanmaz on 4 Jan 2016

@UgurAldanmaz Might be taking a look at the ReadOnlyCollection might help.

s-sreenath on 4 Jan 2016

:+1: I will, @Page-Not-Found. Thanks!

UgurAldanmaz on 5 Jan 2016

Is there any activity on this one?

304NotModified on 4 Feb 2016

@fresa

Looked at this one for the 4.3 release. The proposal looks good, but too bad it isn't backwards compatible as we are missing a clear method. Any idea if we can implement that one?

304NotModified on 14 Feb 2016

@304NotModified: Use the FreeNamedDataSlot method to clear a data slot.

https://msdn.microsoft.com/en-us/library/system.runtime.remoting.messaging.callcontext.freenameddataslot(v=vs.110).aspx

Fresa on 15 Feb 2016

Thanks! Will try to fix this for 4.4

304NotModified on 15 Feb 2016

Recently I got the same problem with MDLC as described here: http://stackoverflow.com/questions/35427859/problems-with-mappeddiagnosticslogicalcontext-in-nlog

And I found the simple solution that works excellent by solving: _"2. Updates in childs should be only visible in the child who has updated it"_ and _"3. Updates in childs should not be visible to the parent"_ issues and also it could be 100% compatible with current behavior:

``` c#
public static class MappedDiagnosticsLogicalContext
{
private const string LogicalThreadDictionaryKey = "NLog.AsyncableMappedDiagnosticsContext";
private const string LogicalThreadDictionaryOwnerKey = "NLog.AsyncableMappedDiagnosticsContextOwner";

public static bool CompatibilityMode;  // Force current "weird mutable dictionary" behavior

private static IDictionary<string, object> LogicalThreadDictionary
{
    get
    {
        var dictionary = CallContext.LogicalGetData(LogicalThreadDictionaryKey) as ConcurrentDictionary<string, object>;
        if (dictionary == null)
        {
            dictionary = new ConcurrentDictionary<string, object>();
            CallContext.LogicalSetData(LogicalThreadDictionaryKey, dictionary);
            if (!CompatibilityMode) CallContext.LogicalSetData(LogicalThreadDictionaryOwnerKey, Thread.CurrentThread.ManagedThreadId);
        }
        else if (!CompatibilityMode && (int)CallContext.LogicalGetData(LogicalThreadDictionaryOwnerKey) != Thread.CurrentThread.ManagedThreadId)
        {
            // Clone dictionary for every new thread
            dictionary = new ConcurrentDictionary<string, object>(dictionary);
            CallContext.LogicalSetData(LogicalThreadDictionaryKey, dictionary);
            CallContext.LogicalSetData(LogicalThreadDictionaryOwnerKey, Thread.CurrentThread.ManagedThreadId);
        }
        return dictionary;
    }
}

// Remaining part of MappedDiagnosticsLogicalContext class ...

```

Regarding _"1. Updates set in parent should be visible in childs"_ - I think there should not be such requirement at all as this prevents assigning of different context items to different child thread (as shown in stackoverflow.com article mentioned above).

vlardn on 12 Sep 2016

I think we could drop the current behaviour, but could we implement these methods?

  /// <summary>
        /// Returns all item names
        /// </summary>
        /// <returns>A collection of the names of all items in current logical context.</returns>
        public static ICollection<string> GetNames()
        {
            return LogicalThreadDictionary.Keys;
        }

        /// <summary>
        /// Checks whether the specified <paramref name="item"/> exists in current logical context.
        /// </summary>
        /// <param name="item">Item name.</param>
        /// <returns>A boolean indicating whether the specified <paramref name="item"/> exists in current logical context.</returns>
        public static bool Contains(string item)
        {
            return LogicalThreadDictionary.ContainsKey(item);
        }

304NotModified on 12 Sep 2016

... could we implement these methods?

What's wrong with these GetNames() and Contains(string item) methods? They work without any problem now (with my fix).

vlardn on 13 Sep 2016

I think we could drop the current behaviour

Regarding current behavior I also think it's not really useful and could be removed. If so - the CompatibilityMode flag and its usage should be removed from my proposed changes.

Should I make pull request to get MDLC fixed in the next NLog version?

vlardn on 13 Sep 2016

👍1