${GDC} reading is now lockfree #3201

snakefoot · 2019-03-26T19:02:16Z

GlobalDiagnosticsContext - Use copy-on-write and lockfree read

Codecov Report

Merging #3201 into dev will increase coverage by <1%.
The diff coverage is 98%.

@@          Coverage Diff           @@
##             dev   #3201    +/-   ##
======================================
+ Coverage     80%     80%   +<1%     
======================================
  Files        354     354            
  Lines      27927   27954    +27     
  Branches    3709    3713     +4     
======================================
+ Hits       22265   22295    +30     
+ Misses      4597    4595     -2     
+ Partials    1065    1064     -1

snakefoot · 2019-03-26T19:54:03Z

The ordering can be important in the expanding of variables that reference other variables. So reverted back to only using ConcurrentDictionary for GlobalDiagnosticsContext

304NotModified · 2019-03-26T20:45:28Z

Isn't the concurrent queue much slower then the lock?

snakefoot · 2019-03-26T20:46:24Z

Isn't the concurrent queue much slower then the lock?

Not if you have two threads (Btw. it is a ConcurrentDictionary) and you don't call:

ConcurrentDictionary.Count
ConcurrentDictionary.IsEmpty
ConcurrentDictionary.Keys
ConcurrentDictionary.Values

See also https://ayende.com/blog/179329/public-service-announcement-concurrentdictionary-count-is-locking

304NotModified · 2019-03-26T21:01:26Z

Not sure it's coincidence this tests fails now :

NLog.UnitTests.Targets.ConcurrentFileTargetTests.SimpleConcurrentTest(numProcesses: 2, numLogs: 500, mode: "none|archive") [FAIL]
At C:\projects\nlog\run-tests.ps1:33 char:1

& ${env:xunit20}\xunit.console.x86.exe .\tests\NLog.UnitTests\bin\rel ...

From
https://ci.appveyor.com/project/nlog/nlog/builds/23379399

304NotModified · 2019-03-26T20:46:09Z

tests/NLog.UnitTests/Layouts/JsonLayoutTests.cs

@@ -506,7 +506,7 @@ public void IncludeGdcJsonProperties()
            <targets>
                <target name='asyncDebug' type='AsyncWrapper' timeToSleepBetweenBatches='0'>
                <target name='debug' type='Debug'  >
-                 <layout type=""JsonLayout"" IncludeGdc='true' ExcludeProperties='Excluded1,Excluded2'>
+                 <layout type=""JsonLayout"" IncludeGdc='true' IncludeAllProperties='true' ExcludeProperties='Excluded1,Excluded2'>


Even with your comment, I don't understand why this has changed :/

Dictionary makes a very good promise to return items in the same order as inserted (Though not always). ConcurrentDictionary doesn't make this promise.

I have modified the test so GDC only contains the first property, and rest of the properties comes from the LogEvent.

snakefoot · 2019-03-26T21:26:06Z

Not sure it's coincidence this tests fails now :

Always been an unstable test. Concurrent processes writing to the same file test is not affected by this change.

snakefoot · 2019-03-26T21:40:08Z

I think the trouble and the surprises with ConcurrentDictionary will outweight the gain unless in a truly multithreaded environment that is doing nothing but GDC-lookups.

Even using readerwriterlockslim will probably have some side-effects:

https://blogs.msdn.microsoft.com/pedram/2007/10/07/a-performance-comparison-of-readerwriterlockslim-with-readerwriterlock/

snakefoot · 2019-03-26T22:19:34Z

@304NotModified Now modified GDC to perform copy on write. This gives high concurrency for loggers but more allocation for writers (if they write a lot while others are reading).

Have the nice side-effect that GlobalDiagnosticsContext.GetNames() suddenly becomes threadsafe.

304NotModified · 2019-03-27T01:27:57Z

@snakefoot is this one safe for NLog 4.6.1? (So low impact)?

snakefoot · 2019-03-27T06:19:59Z

I think it is safe for NLog 4.6.1. One could also consider using the same approach for NLog Configuration Variables.

304NotModified · 2019-03-27T08:08:23Z

src/NLog/GlobalDiagnosticsContext.cs

@@ -69,7 +68,7 @@ public static void Set(string item, object value)
        {
            lock (dict)
            {
-                dict[item] = value;
+                GetWritableDict(dictReadOnly != null && !dict.ContainsKey(item))[item] = value;


Yes one could probably make one of the Setters call the other.

304NotModified · 2019-03-27T22:08:05Z

src/NLog/GlobalDiagnosticsContext.cs

            {
-                dict.Clear();
+                var newDict = new Dictionary<string, object>(clone ? _dict.Count + 1 : 0);


Is it correct that clear has the init capacity of 0, and the field has the default capacity (16?). It that on purpose?

Don't understand your question. But Clear (clone=false) calls with capacity = 0 that means do not allocate internal arrays until insert happens.

indeed, but the init doesn't set capacity to 0

private static Dictionary<string, object> _dict = new Dictionary<string, object>();

Still don't understand your question. The default constructor for Dictionary uses capacity = 0. See also https://referencesource.microsoft.com/#mscorlib/system/collections/generic/dictionary.cs,85 (Means do not allocate until insert happens)

304NotModified · 2019-03-27T22:09:12Z

please check snakefoot#5 :)

…eview)

snakefoot · 2019-03-27T23:01:42Z

@304NotModified Have now extracted the clone-logic from GetWritableDict

src/NLog/GlobalDiagnosticsContext.cs

…eview)

304NotModified

thanks for the refactoring!

snakefoot · 2019-03-28T23:32:28Z

Happy to do it. And also very happy about the result :)

snakefoot mentioned this pull request Mar 26, 2019

MdlcLayoutRenderer not marked with ThreadAgnostic #3197

Closed

snakefoot force-pushed the GdcConcurrentDictionary branch from 01c1462 to 8826d56 Compare March 26, 2019 19:25

snakefoot force-pushed the GdcConcurrentDictionary branch from 8826d56 to 5160ae8 Compare March 26, 2019 19:52

snakefoot changed the title ~~GlobalDiagnosticsContext + Config Variables - Use ConcurrentDictionary~~ GlobalDiagnosticsContext - Use ConcurrentDictionary Mar 26, 2019

304NotModified reviewed Mar 26, 2019

View reviewed changes

PrecalculateVolatileLayouts without lock for initial Layout

85f92d4

snakefoot force-pushed the GdcConcurrentDictionary branch from 4b53bf0 to 85f92d4 Compare March 26, 2019 21:38

snakefoot changed the title ~~GlobalDiagnosticsContext - Use ConcurrentDictionary~~ PrecalculateVolatileLayouts without lock for initial Layout Mar 26, 2019

snakefoot changed the title ~~PrecalculateVolatileLayouts without lock for initial Layout~~ GlobalDiagnosticsContext - Use copy-on-write and lockfree read Mar 26, 2019

GlobalDiagnosticsContext - Clone on write and no lock on read

37aa6ec

snakefoot force-pushed the GdcConcurrentDictionary branch from ade07df to 37aa6ec Compare March 27, 2019 06:35

304NotModified added enhancement Improvement on existing feature performance labels Mar 27, 2019

304NotModified added this to the 4.6.1 milestone Mar 27, 2019

rename fields

0d1f532

304NotModified reviewed Mar 27, 2019

View reviewed changes

snakefoot added 2 commits March 27, 2019 23:14

GlobalDiagnosticsContext - Clone on write and no lock on read (code r…

f5b90c5

…eview)

GlobalDiagnosticsContext - Clone on write and no lock on read (code r…

e6cd4aa

…eview)

304NotModified reviewed Mar 27, 2019

View reviewed changes

src/NLog/GlobalDiagnosticsContext.cs Outdated Show resolved Hide resolved

304NotModified self-assigned this Mar 28, 2019

snakefoot force-pushed the GdcConcurrentDictionary branch from f75267d to f913a69 Compare March 28, 2019 06:14

GlobalDiagnosticsContext - Clone on write and no lock on read (code r…

3d1d030

…eview)

snakefoot force-pushed the GdcConcurrentDictionary branch from f913a69 to 3d1d030 Compare March 28, 2019 18:13

304NotModified changed the title ~~GlobalDiagnosticsContext - Use copy-on-write and lockfree read~~ ${GDC} reading is now lockfree Mar 28, 2019

304NotModified approved these changes Mar 28, 2019

View reviewed changes

304NotModified merged commit 80b1e85 into NLog:dev Mar 28, 2019

snakefoot deleted the GdcConcurrentDictionary branch April 4, 2020 12:59

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

${GDC} reading is now lockfree #3201

${GDC} reading is now lockfree #3201

snakefoot commented Mar 26, 2019 •

edited by 304NotModified

Loading

snakefoot commented Mar 26, 2019

codecov bot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

304NotModified commented Mar 26, 2019

snakefoot commented Mar 26, 2019 •

edited

Loading

304NotModified commented Mar 26, 2019

304NotModified Mar 26, 2019

snakefoot Mar 26, 2019

snakefoot Mar 26, 2019

snakefoot commented Mar 26, 2019

snakefoot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

304NotModified commented Mar 27, 2019

snakefoot commented Mar 27, 2019

304NotModified Mar 27, 2019

snakefoot Mar 27, 2019

304NotModified Mar 27, 2019

snakefoot Mar 27, 2019

304NotModified Mar 27, 2019 •

edited

Loading

snakefoot Mar 27, 2019 •

edited

Loading

304NotModified commented Mar 27, 2019

snakefoot commented Mar 27, 2019

304NotModified left a comment

snakefoot commented Mar 28, 2019

${GDC} reading is now lockfree #3201

${GDC} reading is now lockfree #3201

Conversation

snakefoot commented Mar 26, 2019 • edited by 304NotModified Loading

snakefoot commented Mar 26, 2019

codecov bot commented Mar 26, 2019 • edited Loading

Codecov Report

snakefoot commented Mar 26, 2019 • edited Loading

304NotModified commented Mar 26, 2019

snakefoot commented Mar 26, 2019 • edited Loading

304NotModified commented Mar 26, 2019

304NotModified Mar 26, 2019

Choose a reason for hiding this comment

snakefoot Mar 26, 2019

Choose a reason for hiding this comment

snakefoot Mar 26, 2019

Choose a reason for hiding this comment

snakefoot commented Mar 26, 2019

snakefoot commented Mar 26, 2019 • edited Loading

snakefoot commented Mar 26, 2019 • edited Loading

304NotModified commented Mar 27, 2019

snakefoot commented Mar 27, 2019

304NotModified Mar 27, 2019

Choose a reason for hiding this comment

snakefoot Mar 27, 2019

Choose a reason for hiding this comment

304NotModified Mar 27, 2019

Choose a reason for hiding this comment

snakefoot Mar 27, 2019

Choose a reason for hiding this comment

304NotModified Mar 27, 2019 • edited Loading

Choose a reason for hiding this comment

snakefoot Mar 27, 2019 • edited Loading

Choose a reason for hiding this comment

304NotModified commented Mar 27, 2019

snakefoot commented Mar 27, 2019

304NotModified left a comment

Choose a reason for hiding this comment

snakefoot commented Mar 28, 2019

snakefoot commented Mar 26, 2019 •

edited by 304NotModified

Loading

codecov bot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

snakefoot commented Mar 26, 2019 •

edited

Loading

304NotModified Mar 27, 2019 •

edited

Loading

snakefoot Mar 27, 2019 •

edited

Loading