Strange. Would you please do a safety check whether other things were reverted too?
2013/11/16 Stefan Bodewig (JIRA) <j...@apache.org> > > [ > https://issues.apache.org/jira/browse/LOG4NET-376?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13824405#comment-13824405] > > Stefan Bodewig commented on LOG4NET-376: > ---------------------------------------- > > I'm afraid svn revision 1486883 > http://svn.apache.org/viewvc/logging/log4net/trunk/src/log4net/DateFormatter/AbsoluteTimeDateFormatter.cs?r1=1483378&r2=1486883has > reverted the locking that Dominik had introduced. I'll bring them back > for 1.2.13 and also verify we don't access the dictionary outside of a lock. > > > Race condition in AbsoluteTimeDateFormatter > > ------------------------------------------- > > > > Key: LOG4NET-376 > > URL: https://issues.apache.org/jira/browse/LOG4NET-376 > > Project: Log4net > > Issue Type: Bug > > Affects Versions: 1.2.11 > > Reporter: Stuart Lange > > > > AbsoluteTimeDateFormatter's caching of the "to the second" timestamp > string is not thread-safe. It is possible for one thread to clear the > check (that this timestamp matches the currently cached "to the second" > timestamp), but then end up using an incorrect "to the second" timestamp > string if another thread has changed it in the meantime. > > In our organization, we see this bug fairly regularly because we have a > mix of "real time" loggers that immediately write out log lines and > "batching" loggers that defer logging to a background task that runs every > second. We therefore regularly see log lines where the timestamp is off by > a second or two. > > The following unit tests demonstrates the bug: > > [TestFixture] > > [Explicit] > > public class Log4netTimestampBug > > { > > /// <summary> > > /// This test demonstrates a bug with the log4net default time > formatter (Iso8601DateFormatter) > > /// where the logged timestamp can be seconds off from the > actual input timestamp > > /// The bug is caused to a race condition in the base class > AbsoluteTimeDateFormatter > > /// because this class caches the timestamp string to the second > but it is possible for > > /// the timestamp as written by a different thread to "sneak in" > and be used by another > > /// thread erroneously (the checking and usage of this string is > not done under a lock, only > > /// its modification) > > /// </summary> > > [Test] > > public void Test() > > { > > var now = DateTime.Now; > > var times = Enumerable.Range(1, 1000000).Select(i => > now.AddMilliseconds(i)).ToList(); > > var sb1 = new StringBuilder(); > > var sb2 = new StringBuilder(); > > var task1 = Task.Run(() => WriteAllTheTimes(times, new > StringWriter(sb1))); > > var task2 = Task.Delay(50).ContinueWith(t => > WriteAllTheTimes(times, new StringWriter(sb2))); > > Task.WaitAll(task1, task2); > > var task1Strings = GetTimeStrings(sb1); > > var task2Strings = GetTimeStrings(sb2); > > var diffs = Enumerable.Range(0, times.Count).Where(i => > task1Strings[i] != task2Strings[i]).ToList(); > > Console.WriteLine("found {0} instances where the formatted > timestamps are not the same", diffs.Count); > > Console.WriteLine(); > > var diffToLookAt = diffs.FirstOrDefault(i => i - 10 > 0 && i > + 10 < times.Count); > > if (diffToLookAt != 0) > > { > > Console.WriteLine("Example Diff:"); > > Console.WriteLine(); > > Console.WriteLine("Index Original Timestamp > Task 1 Format Task 2 Format"); > > for (int i = diffToLookAt - 10; i < diffToLookAt + 10; > i++) > > { > > Console.WriteLine("{0,-7} {1} {2} {3} {4}", > i, times[i].ToString("yyyy-MM-dd HH:mm:ss,fff"), > > task1Strings[i], task2Strings[i], > i == diffToLookAt ? "**** DIFF HERE ****" : ""); > > } > > } > > CollectionAssert.AreEqual(task1Strings, task2Strings); > > } > > private static List<string> GetTimeStrings(StringBuilder sb1) > > { > > return sb1.ToString().Split(new[] {'\r', '\n'}, > StringSplitOptions.RemoveEmptyEntries).ToList(); > > } > > private static void WriteAllTheTimes(IEnumerable<DateTime> times, > > TextWriter writer) > > { > > var formatter = new Iso8601DateFormatter(); > > foreach (var t in times) > > { > > formatter.FormatDate(t, writer); > > writer.WriteLine(); > > } > > } > > } > > > > -- > This message was sent by Atlassian JIRA > (v6.1#6144) > -- Dominik Psenner
