Re: [VOTE] Release Log4Net 1.2.13 based on RC2
On 2013-11-13, Dominik Psenner wrote: > 0 > LOG4NET-405 jumped in and I am about to commit a fix. I'm not comfortable with putting that into 1.2.13. This changes a default value which in turn might byte people relying on the old default. I don't have any problem with changing the default for 1.3. Stefan
AW: [VOTE] Release Log4Net 1.2.13 based on RC2
To me it looks like I've broken the prior behaviour while trying to fix LOG4NET-354 and LOG4NET-405 remedies that. *ouch* Quoting: http://msdn.microsoft.com/en-us/library/system.net.mail.mailmessage.headerse ncoding(v=vs.110).aspx > The value of the HeadersEncoding property defaults to Encoding.UTF8 whereas Encoding.Default will most likely yield something different. Quoting: http://msdn.microsoft.com/en-us/library/system.net.mail.mailmessage.bodyenco ding(v=vs.110).aspx > The default character set is "us-ascii". Here they do not mention the default encoding, but it will most likely be Encoding.ASCII whereas Encoding.Default will most likely yield something different.
Re: [VOTE] Release Log4Net 1.2.13 based on RC2
On 2013-11-13, Dominik Psenner wrote: > To me it looks like I've broken the prior behaviour while trying to fix > LOG4NET-354 and LOG4NET-405 remedies that. *ouch* I see > Quoting: > http://msdn.microsoft.com/en-us/library/system.net.mail.mailmessage.bodyenco > ding(v=vs.110).aspx >> The default character set is "us-ascii". > Here they do not mention the default encoding, but it will most likely be > Encoding.ASCII whereas Encoding.Default will most likely yield something > different. Shouldn't we change body encoding's default to ASCII, then? Stefan
[CANCELED][VOTE] Release Log4Net 1.2.13 based on RC2
Cancelling this vote as a bug has showned up that we want to fix before cutting another release candidate. Stefan
Re: [VOTE] Release Log4Net 1.2.13 based on RC2
Thought of that too, but I decided to let it be in UTF8 cause its the most compatible format nowadays whereas ASCII is somewhat antique. What do you think? 2013/11/13 Stefan Bodewig > On 2013-11-13, Dominik Psenner wrote: > > > To me it looks like I've broken the prior behaviour while trying to fix > > LOG4NET-354 and LOG4NET-405 remedies that. *ouch* > > I see > > > Quoting: > > > http://msdn.microsoft.com/en-us/library/system.net.mail.mailmessage.bodyenco > > ding(v=vs.110).aspx > > >> The default character set is "us-ascii". > > > Here they do not mention the default encoding, but it will most likely be > > Encoding.ASCII whereas Encoding.Default will most likely yield something > > different. > > Shouldn't we change body encoding's default to ASCII, then? > > Stefan > -- Dominik Psenner
[jira] [Commented] (LOG4NET-376) Race condition in AbsoluteTimeDateFormatter
[
https://issues.apache.org/jira/browse/LOG4NET-376?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13821734#comment-13821734
]
Stuart Lange commented on LOG4NET-376:
--
Hello again. Sorry for letting this slide for a while.
We've noticed that with the log4net 1.2.12 service release, this bug has
actually gotten considerably worse. We have run into scenarios where the "to
the second" component of the timestamp gets "stuck" and never updates again for
the duration of the application. Unfortunately, I have been unable to produce
a unit test that reliably reproduces the issue (the unit test above sometimes
reproduces it), but my best guess is that this is related to the addition of
the Hashtable in AbsoluteTimeDateFormatter in LOG4NET-323. The Hashtable is
cleared and read from outside the lock, which can lead to potential race
conditions since the Hashtable is not thread-safe.
I have created my own implementation of IDateFormatter that behaves identically
to Iso8601DateFormatter, but avoids the bugs noted in this issue. My
performance testing shows that it performs nearly identically to
Iso8601DateFormatter in typical scenarios, and actually performs substantially
better in multi-threaded scenarios. I chose to make the cache state
ThreadStatic as that performs marginally better than the other options (static,
instance) in my performance testing, but the other options also perform well
and behave equivalently. Code is below. If you would like to see my
performance testing code, I can send you that as well, but it uses some of my
own custom components that would require unpacking to post in copy-paste
friendly form.
public class StandardDateFormatter : IDateFormatter
{
// Using ThreadStatic is a micro-optimization. Making it static or
instance state also works.
// ThreadStatic performs marginally better in scenarios where the same
instance of the formatter
// is being hit from multiple threads that are using different
timestamps.
// Performance is roughly equivalent in single-threaded scenarios.
[ThreadStatic]
private static Tuple _lastTicksToTheSecond;
public void FormatDate(DateTime dateToFormat, TextWriter writer)
{
var ticksToTheSecond = dateToFormat.Ticks - dateToFormat.Ticks %
TimeSpan.TicksPerSecond;
var lastToTheSecond = _lastTicksToTheSecond;
string toTheSecondString;
if (lastToTheSecond != null && lastToTheSecond.Item1 ==
ticksToTheSecond)
{
toTheSecondString = lastToTheSecond.Item2;
}
else
{
toTheSecondString = dateToFormat.ToString("-MM-dd
HH:mm:ss");
_lastTicksToTheSecond = Tuple.Create(ticksToTheSecond,
toTheSecondString);
}
writer.Write(toTheSecondString);
writer.Write(',');
var millisecond = dateToFormat.Millisecond;
if (millisecond < 100)
writer.Write('0');
if (millisecond < 10)
writer.Write('0');
writer.Write(millisecond);
}
}
> 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
>Assignee: Dominik Psenner
> Fix For: 1.2.12
>
>
> 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
> {
> ///
> /// 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
>
[jira] [Comment Edited] (LOG4NET-376) Race condition in AbsoluteTimeDateFormatter
[
https://issues.apache.org/jira/browse/LOG4NET-376?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13821734#comment-13821734
]
Stuart Lange edited comment on LOG4NET-376 at 11/13/13 7:37 PM:
Hello again. Sorry for letting this slide for a while.
We've noticed that with the log4net 1.2.12 service release, this bug has
actually gotten considerably worse. We have run into scenarios where the "to
the second" component of the timestamp gets "stuck" and never updates again for
the duration of the application. Unfortunately, I have been unable to produce
a unit test that reliably reproduces the issue (the unit test above sometimes
reproduces it), but my best guess is that this is related to the addition of
the Hashtable in AbsoluteTimeDateFormatter in LOG4NET-323. The Hashtable is
cleared and read from outside the lock, which can lead to potential race
conditions since the Hashtable is not thread-safe.
I have created my own implementation of IDateFormatter that behaves identically
to Iso8601DateFormatter, but avoids the bugs noted in this issue. My
performance testing shows that it performs nearly identically to
Iso8601DateFormatter in typical scenarios, and actually performs substantially
better in multi-threaded scenarios. I chose to make the cache state
ThreadStatic as that performs marginally better than the other options (static,
instance) in my performance testing, but the other options also perform well
and behave equivalently. Code is below. If you would like to see my
performance testing code, I can send you that as well, but it uses some of my
own custom components that would require unpacking to post in copy-paste
friendly form.
{code}
public class StandardDateFormatter : IDateFormatter
{
// Using ThreadStatic is a micro-optimization. Making it static or
instance state also works.
// ThreadStatic performs marginally better in scenarios where the same
instance of the formatter
// is being hit from multiple threads that are using different
timestamps.
// Performance is roughly equivalent in single-threaded scenarios.
[ThreadStatic]
private static Tuple _lastTicksToTheSecond;
public void FormatDate(DateTime dateToFormat, TextWriter writer)
{
var ticksToTheSecond = dateToFormat.Ticks - dateToFormat.Ticks %
TimeSpan.TicksPerSecond;
var lastToTheSecond = _lastTicksToTheSecond;
string toTheSecondString;
if (lastToTheSecond != null && lastToTheSecond.Item1 ==
ticksToTheSecond)
{
toTheSecondString = lastToTheSecond.Item2;
}
else
{
toTheSecondString = dateToFormat.ToString("-MM-dd
HH:mm:ss");
_lastTicksToTheSecond = Tuple.Create(ticksToTheSecond,
toTheSecondString);
}
writer.Write(toTheSecondString);
writer.Write(',');
var millisecond = dateToFormat.Millisecond;
if (millisecond < 100)
writer.Write('0');
if (millisecond < 10)
writer.Write('0');
writer.Write(millisecond);
}
}
{code}
was (Author: slange):
Hello again. Sorry for letting this slide for a while.
We've noticed that with the log4net 1.2.12 service release, this bug has
actually gotten considerably worse. We have run into scenarios where the "to
the second" component of the timestamp gets "stuck" and never updates again for
the duration of the application. Unfortunately, I have been unable to produce
a unit test that reliably reproduces the issue (the unit test above sometimes
reproduces it), but my best guess is that this is related to the addition of
the Hashtable in AbsoluteTimeDateFormatter in LOG4NET-323. The Hashtable is
cleared and read from outside the lock, which can lead to potential race
conditions since the Hashtable is not thread-safe.
I have created my own implementation of IDateFormatter that behaves identically
to Iso8601DateFormatter, but avoids the bugs noted in this issue. My
performance testing shows that it performs nearly identically to
Iso8601DateFormatter in typical scenarios, and actually performs substantially
better in multi-threaded scenarios. I chose to make the cache state
ThreadStatic as that performs marginally better than the other options (static,
instance) in my performance testing, but the other options also perform well
and behave equivalently. Code is below. If you would like to see my
performance testing code, I can send you that as well, but it uses some of my
own custom components that would require unpacking to post in copy-paste
friendly form.
public class StandardDateFormatter : IDateFormatter
{
// Using ThreadStatic is a micro-optimization. Making it static or
instance s
LOG4NET-405 (was Re: [VOTE] Release Log4Net 1.2.13 based on RC2)
On 2013-11-13, Dominik Psenner wrote: > Thought of that too, but I decided to let it be in UTF8 cause its the most > compatible format nowadays whereas ASCII is somewhat antique. What do you > think? IIUC ASCII would have been the implicit body encoding for log4net < 1.2.12 so when looking for a backwards compatible default this would be the most natural choice. I'm not sure whether setting the encoding to UTF8 triggers some sort of different handling inside of the framweork's SMTP code even if the test was pure ASCII. If it doesn't, then I'm fine with UTF8. Maybe we should send two messages with a body only containing ASCII letters and compare the raw messages created with encoding set to ASCII or UTF8 respectively. Stefan
