[LOG4NET-626] Incorrect log entries order for multiple threads

• Type: Bug
• Status: Open
• Priority: Major
• Resolution: Unresolved
• Component/s: Other
• Environment: windows server 2016
• Assignee: Unassigned
• Reporter: Tonik
• Created: 03/Mar/19 10:19
• Updated: 04/Apr/20 22:28

Description

i'm using RollingLogFileAppender

i'm using log4net from multiple threads (~ 150 Tasks)
and timetstamp are ordered incorrectly, see sample.
you can see that sometimes i get log timestamps from past time. sometimes its only 
100 ms ago, sometimes like 1 second.

2019-02-24 00:00:22,085 [389] DEBUG [Worker TPID: 448] - XXXXXXXXXX
2019-02-24 00:00:22,085 [389] DEBUG [Worker TPID: 436] - XXXXXXXXXX
2019-02-24 00:00:22,163 [230] DEBUG [Worker TPID: 435] - XXXXXXXXXX
2019-02-24 00:00:22,132 [387] DEBUG [Worker TPID: 242] - XXXXXXXXXX
2019-02-24 00:00:22,132 [329] DEBUG [Worker TPID: 583] - XXXXXXXXXX
2019-02-24 00:00:22,163 [387] DEBUG [Worker TPID: 242] - XXXXXXXXXX
2019-02-24 00:00:22,132 [251] DEBUG [Worker TPID: 373] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 373] - XXXXXXXXXX
2019-02-24 00:00:22,148 [452] DEBUG [Worker TPID: 244] - XXXXXXXXXX
2019-02-24 00:00:22,148 [351] DEBUG [Worker TPID: 391] - XXXXXXXXXX
2019-02-24 00:00:22,163 [452] DEBUG [Worker TPID: 393] - XXXXXXXXXX
2019-02-24 00:00:22,163 [452] DEBUG [Worker TPID: 553] - XXXXXXXXXX
2019-02-24 00:00:22,163 [351] DEBUG [Worker TPID: 393] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 244] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 244] - XXXXXXXXXX
2019-02-24 00:00:22,163 [109] DEBUG [Worker TPID: 408] - XXXXXXXXXX
2019-02-24 00:00:22,163 [109] DEBUG [Worker TPID: 408] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 553] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 553] - XXXXXXXXXX
2019-02-24 00:00:22,163 [452] DEBUG [Worker TPID: 569] - XXXXXXXXXX
2019-02-24 00:00:22,163 [351] DEBUG [Worker TPID: 393] - XXXXXXXXXX
2019-02-24 00:00:22,163 [452] DEBUG [Worker TPID: 585] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 569] - XXXXXXXXXX
2019-02-24 00:00:22,163 [251] DEBUG [Worker TPID: 569] - XXXXXXXXXX
2019-02-24 00:00:22,163 [351] DEBUG [Worker TPID: 585] - XXXXXXXXXX
2019-02-24 00:00:22,085 [468] DEBUG [Worker TPID: 360] - XXXXXXXXXX
2019-02-24 00:00:22,163 [468] DEBUG [Worker TPID: 360] - XXXXXXXXXX
2019-02-24 00:00:22,163 [323] DEBUG [Worker TPID: 244] - XXXXXXXXXX
2019-02-24 00:00:22,163 [323] DEBUG [Worker TPID: 244] - XXXXXXXXXX
2019-02-24 00:00:22,163 [452] DEBUG [Worker TPID: 585] - XXXXXXXXXX
2019-02-24 00:00:22,163 [468] DEBUG [Worker TPID: 569] - XXXXXXXXXX
2019-02-24 00:00:22,163 [468] DEBUG [Worker TPID: 569] - XXXXXXXXXX
2019-02-24 00:00:22,148 [377] DEBUG [Worker TPID: 238] - XXXXXXXXXX
2019-02-24 00:00:22,163 [377] DEBUG [Worker TPID: 238] - XXXXXXXXXX
2019-02-24 00:00:22,132 [244] DEBUG [Worker TPID: 356] - XXXXXXXXXX
2019-02-24 00:00:22,163 [244] DEBUG [Worker TPID: 356] - XXXXXXXXXX
2019-02-24 00:00:22,945 [283] DEBUG [Worker TPID: 87] - XXXXXXXXXX
2019-02-24 00:00:22,945 [283] DEBUG [Worker TPID: 323] - XXXXXXXXXX
2019-02-24 00:00:22,945 [283] DEBUG [Worker TPID: 359] - XXXXXXXXXX