[jira] [Created] (LOG4NET-434) Changing file path of RollingFileAppender

[Dina Goldshtein (JIRA)]

Dina Goldshtein created LOG4NET-434:
---

 Summary: Changing file path of RollingFileAppender
 Key: LOG4NET-434
 URL: https://issues.apache.org/jira/browse/LOG4NET-434
 Project: Log4net
  Issue Type: Bug
  Components: Appenders
Affects Versions: 1.2.13
 Environment: Windows 7 x64, .NET 4.0, C# 5
Reporter: Dina Goldshtein
Priority: Minor


I have configured a rolling file appender which is supposed to roll every 
minute or every 10KB:

{code:xml}


















{code}

Then in my main I change the path of the appender:

{code}
LogUtilities.ChangeFileAppenderPath("SmsRollingFile", "sms_pc.log");
{code}

where ChangeFileAppenderPath is defined as follows;
{code}
public static void ChangeFileAppenderPath(string appenderName, string path)
{
if (string.IsNullOrEmpty(path))
{
throw new ArgumentNullException("path");
}

ILoggerRepository repository = LogManager.GetRepository();
foreach (IAppender appender in repository.GetAppenders())
{
if (appender.Name == appenderName)
{
var file = appender as FileAppender;
if (file == null)
{
throw new ArgumentException("Must provide appender name 
for an appender fo type FileAppender",
"appenderName");
}
file.File = path;
file.ActivateOptions();
return;
}
}

throw new ArgumentException("Appender name not valid", 
"appenderName");
}
{code}

And my main method simply writes to the log in a loop;
{code}
while (true)
{
Thread.Sleep(100);
LogUtilities.GetInstance("Test").Debug("Test - 1 - 2 - 3");
}
{code}

Most of the time the log is written and rolled in the correct location - the 
working directory of the process, however, from time to time (I haven't been 
able to determine the conditions at which this happens) the rolled log is moved 
to the original location at "C:\\ProgramData\\BSII\\SMS\\.
I noticed that even after I change the file path for the appender, it still has 
a field called m_scheduledFilename which points to 
"C:\\ProgramData\\BSII\\SMS\\sms_20140602-0915.log". 



--
This message was sent by Atlassian JIRA
(v6.2#6252)

[jira] [Comment Edited] (LOG4NET-429) Pattern with Context property causes severe slowdown

[Stefan Bodewig (JIRA)]

[ 
https://issues.apache.org/jira/browse/LOG4NET-429?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14015049#comment-14015049
 ] 

Stefan Bodewig edited comment on LOG4NET-429 at 6/1/14 6:00 PM:


I like the way you've lifted the code to SystemInfo

Personally I would probably add a new ReadOnlyPropertiesDictionary with the 
lazy loading semantics and add that to the m_compositeProperties instance 
rather than add the caching inside ComositeProperties but I haven't got any 
working code to show right now and your solution works just as well.


was (Author: bodewig):
I like the way you've moved lifted the code to SystemInfo

Personally I would probably add a new ReadOnlyPropertiesDictionary with the 
lazy loading semantics and add that to the m_compositeProperties instance 
rather than add the caching inside ComositeProperties but I haven't got any 
working code to show right now and your solution works just as well.

> Pattern with Context property causes severe slowdown
> 
>
> Key: LOG4NET-429
> URL: https://issues.apache.org/jira/browse/LOG4NET-429
> Project: Log4net
>  Issue Type: Improvement
>  Components: Core
>Affects Versions: 1.2.13
>Reporter: Jonas Versén
>Assignee: Dominik Psenner
>Priority: Minor
>  Labels: performance
> Attachments: LOG4NET-429.patch
>
>
> If you use a context property in your appenders pattern, there will be a 
> significant logging slowdown. In my experience anywhere from 3 to 5 times 
> slower (this will depend on the appender).
> I believe that as soon as you use a context property log4net will internally 
> access the windows user name even though it's not the property you want to 
> access. This theory comes from the fact that printing all properties in the 
> pattern (including the costly property username) compared to just printing 
> one will slow down the logging with the same factor.
> I've made a stackoverflow question with more details as well
> http://stackoverflow.com/questions/22612286/using-log4net-context-properties-has-negative-impact-on-performance/



--
This message was sent by Atlassian JIRA
(v6.2#6252)

[jira] [Commented] (LOG4NET-429) Pattern with Context property causes severe slowdown

[Stefan Bodewig (JIRA)]

[ 
https://issues.apache.org/jira/browse/LOG4NET-429?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14015049#comment-14015049
 ] 

Stefan Bodewig commented on LOG4NET-429:


I like the way you've moved lifted the code to SystemInfo

Personally I would probably add a new ReadOnlyPropertiesDictionary with the 
lazy loading semantics and add that to the m_compositeProperties instance 
rather than add the caching inside ComositeProperties but I haven't got any 
working code to show right now and your solution works just as well.

> Pattern with Context property causes severe slowdown
> 
>
> Key: LOG4NET-429
> URL: https://issues.apache.org/jira/browse/LOG4NET-429
> Project: Log4net
>  Issue Type: Improvement
>  Components: Core
>Affects Versions: 1.2.13
>Reporter: Jonas Versén
>Assignee: Dominik Psenner
>Priority: Minor
>  Labels: performance
> Attachments: LOG4NET-429.patch
>
>
> If you use a context property in your appenders pattern, there will be a 
> significant logging slowdown. In my experience anywhere from 3 to 5 times 
> slower (this will depend on the appender).
> I believe that as soon as you use a context property log4net will internally 
> access the windows user name even though it's not the property you want to 
> access. This theory comes from the fact that printing all properties in the 
> pattern (including the costly property username) compared to just printing 
> one will slow down the logging with the same factor.
> I've made a stackoverflow question with more details as well
> http://stackoverflow.com/questions/22612286/using-log4net-context-properties-has-negative-impact-on-performance/



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Re: log4net 1.2.13 performance issues (found the exact line that causes the problem)

[Stefan Bodewig]

On 2014-06-01, Alexey Polyakov wrote:

> I have encountered a heavy drop in performance after migration from log4net
> 1.2.10 to 1.2.13. My research pointed out to the commit #1511303 and
> specifically to the line 1340:

> eventProperties[UserNameProperty] = UserName;

Seems this is https://issues.apache.org/jira/browse/LOG4NET-429

A possible un-reviewed patch exists, verifying it has been on my TODO
last far too long by now.

Stefan

RE: log4net 1.2.13 performance issues (found the exact line that causes the problem)

[Alexey Polyakov]

Sorry, forgot to attach the file.

 

Best Regards,
Alexey Polyakov 
Software Engineer




EPAM Systems
Ryazan office, Russia 
GMT+3 (Standard) / GMT+3 (Daylight)

Office phone:   +7 (4912) 935-733, ext. 46229

Mobile phone:   +7 (910) 509-96-37

E-mail:  
alexey_polya...@epam.com

Skype:   Aleksey__Polyakov (
 chat or   call)

 

From: Alexey Polyakov [mailto:alexey_polya...@epam.com] 
Sent: Sunday, June 01, 2014 6:49 PM
To: log4net-dev@logging.apache.org
Cc: log4net-u...@logging.apache.org
Subject: RE: log4net 1.2.13 performance issues (found the exact line that
causes the problem)

 

Hello,

 

I have encountered a heavy drop in performance after migration from log4net
1.2.10 to 1.2.13. My research pointed out to the commit #1511303 and
specifically to the line 1340:

 
eventProperties[UserNameProperty] = UserName;

 

I attach the test harness I was using - without this line the logging is
done in about 2 seconds, and after this line is added - it takes 24 seconds.

 

Can you please give any comment on what is going on? (is it safe to just
remove this line and use patched version in production environment, or may
be there is already a work in progress and a better solution)/

 

Best Regards,
Alexey Polyakov 
Software Engineer


EPAM Systems
Ryazan office, Russia 
GMT+3 (Standard) / GMT+3 (Daylight)

Office phone:   +7 (4912) 935-733, ext. 46229

Mobile phone:   +7 (910) 509-96-37

E-mail:  
alexey_polya...@epam.com

Skype:   Aleksey__Polyakov (
 chat or   call)

 

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Text;
using System.Threading;
using System.Threading.Tasks;
using log4net;
using log4net.Appender;
using log4net.Core;
using log4net.Layout;
using log4net.Repository.Hierarchy;

namespace LoadTestApplication
{
class Program
{
static void Main(string[] args)
{
Setup();

var logger = LogManager.GetLogger(typeof(Program));

const int requests = 10;
const int times = 1;

log4net.LogicalThreadContext.Properties["callId"] = Guid.NewGuid();
for (var j = 0; j < times; j++)
{
var stopwatch = new Stopwatch();
stopwatch.Start();

Parallel.For(0, requests, (i, state) =>
  {
  logger.DebugFormat("logging 
request {0}", i);
  });

stopwatch.Stop();
Console.WriteLine("Processing {0} requests took {1}", requests, 
stopwatch.Elapsed);
}
}
public static void Setup()
{
Hierarchy hierarchy = (Hierarchy)LogManager.GetRepository();

PatternLayout patternLayout = new PatternLayout();
patternLayout.ConversionPattern = "%date [%thread, 
%property{callId}] %-5level %logger - %message%newline";
patternLayout.ActivateOptions();

RollingFileAppender roller = new RollingFileAppender();
roller.AppendToFile = true;
roller.CountDirection = 0;
roller.DatePattern = "MMdd";
roller.Encoding = new UTF8Encoding();
roller.File = @"Logs\EventLog.txt";
roller.Layout = patternLayout;
roller.MaxSizeRollBackups = 5;
roller.MaximumFileSize = "1GB";
roller.RollingStyle = RollingFileAppender.RollingMode.Composite;
roller.StaticLogFileName = false;
roller.ActivateOptions();
hierarchy.Root.AddAppender(roller);

hierarchy.Root.Level = Level.All;
hierarchy.Configured = true;
}
}
}


smime.p7s
Description: S/MIME cryptographic signature

RE: log4net 1.2.13 performance issues (found the exact line that causes the problem)

[Alexey Polyakov]

Hello,

 

I have encountered a heavy drop in performance after migration from log4net
1.2.10 to 1.2.13. My research pointed out to the commit #1511303 and
specifically to the line 1340:

 
eventProperties[UserNameProperty] = UserName;

 

I attach the test harness I was using - without this line the logging is
done in about 2 seconds, and after this line is added - it takes 24 seconds.

 

Can you please give any comment on what is going on? (is it safe to just
remove this line and use patched version in production environment, or may
be there is already a work in progress and a better solution)/

 

Best Regards,
Alexey Polyakov 
Software Engineer


EPAM Systems
Ryazan office, Russia 
GMT+3 (Standard) / GMT+3 (Daylight)

Office phone:   +7 (4912) 935-733, ext. 46229

Mobile phone:   +7 (910) 509-96-37

E-mail:  
alexey_polya...@epam.com

Skype:   Aleksey__Polyakov (
 chat or   call)

 



smime.p7s
Description: S/MIME cryptographic signature