Log4Net RollingFileAppender没有使用低容量日志刷新IO缓冲区 [英] Log4Net RollingFileAppender not flushing IO buffer with low volume log

问题描述

我正在思考与HENRI COOK相同的问题。它被报道为关于Apache Jira的错误就我们从简短描述中可以看出来而言。

I'm pondering on the same issue as HENRI COOK did. It's been reported as a bug on Apache Jira as far as we can tell from the short description.

我的问题实质上是只在应用程序关闭时记录事件（甚至在事件发生后几周）。当记录量非常低时会发生这种情况。我在Windows Server 2008 R2上看到了这一点。这可以防止我们捕获并对生产错误做出反应。

My problem in essence is that events are only logged when the application is shut down (even weeks after the event). That happens when logging volume is very low. I'm seeing this on a Windows Server 2008 R2. This prevents us from capturing and reacting to production errors.

现在，appender不是缓冲器。默认情况下，每次附加消息时，它还会在基础流上调用Flush（）。

Now the appender is not a buffering one. By default it also calls Flush() on the underlying stream every time a message is appended.

我的问题是为什么不冲洗？除了以编程方式刷新所有appenders之外，还有什么补救措施？你会考虑 pulsing appender 一个可行的解决方法？

My question is WHY is it not flushing? And is there any remedy besides programatically flushing all appenders? Would you consider a pulsing appender a viable workaround?

appender配置：

The appender config:

<appender name="RollingErrorFileAppender" type="log4net.Appender.RollingFileAppender">
  <param name="File" value="D:\LogFiles\zzzz\xxxxxx__ERROR" />
  <param name="AppendToFile" value="true" />
  <param name="DatePattern" value="_yyyyMMddHH&quot;.log&quot;" />
  <param name="RollingStyle" value="Date" />
  <param name="StaticLogFileName" value="false" />
  <filter type="log4net.Filter.LevelRangeFilter">
    <param name="LevelMin" value="ERROR" />
    <param name="LevelMax" value="FATAL" />
  </filter>
  <layout type="log4net.Layout.PatternLayout">
    <param name="ConversionPattern" value="%utcdate{yyyy-MM-dd HH:mm:ss.fff},[%thread],%level,%logger,%m%n"/>
  </layout>
</appender>

更新2013-06-19

UPDATE 2013-06-19

我无法用任何代码重现行为。无论我尝试多么糟糕，数据总是立即写入磁盘。但是，进行了一项重要的观察：如果对文件的第一次写入大于1KiB，则修改时间永远不会随后写入而更新。只有在关闭时关闭文件时才会更新它。另一方面，如果第一次写入是短的一行，则任何后续写入都将更新修改时间。这种行为在log4net和手动IO操作之间，在32位WinXP和64位W2k8R2之间，在.NET 2.0,3.5和.NET 4.0之间是一致的。这还没有解决问题，但至少我现在可以理解奇怪的修改时间模式。

I haven't been able to reproduce the behavior with any code. No matter how bad I try, the data is always written to the disk immediately. However, an important observation was made: If the first write to a file is larger than 1KiB, the modified-time is never updated with subsequent writes. It will only be updated when the file is closed with the time of closure. If on the other hand the first write is a short one-liner, any subsequent write will update the modified-time. This behavior is consistent between log4net and manual IO operation, between 32bit WinXP and 64bit W2k8R2, between .NET 2.0, 3.5 and .NET 4.0. That doesn't solve the problem still, but at least I can understand the strange modification-time pattern now.

谢谢，Rob

推荐答案

由于您只关心错误级别或更糟糕的日志事件，并且幸运的是流量很少，我建议您将appender配置为立即刷新。

Since you are only concerned with error level or worse log events, and that traffic is fortunately infrequent, I would suggest configuring your appender to immediately flush.

<param name="ImmediateFlush" value="true" />

这使您无需在每个日志事件上以编程方式刷新appender（无论如何都无法正常工作）从它的声音）。现在，如果你希望打开你的appender到更多的日志级别，那么当然立即刷新所有事件可能会有更大的性能问题。

This saves you from having to programmatically flush your appender on every log event (which wasn't working anyway from the sound of it). Now, if you wish to open your appender up to more log levels, then of course immediately flushing all events could have greater performance concerns.

EDIT

我添加了配置文件和一个用于测试的简单主程序。使用以下内容，我确实看到立即刷新日志事件。关于你的评论，我也可以从xml中删除 ImmediateFlush 行，并查看默认的 true 值工作用于冲洗。为了明确说明理想的行为，我在我的例子中保留了这一行。

I added the config file and a simple main program I used for testing. Using the following, I do see log events immediately flushed. In regard to your comment, I can also strip out the ImmediateFlush line from the xml and see the default true value work for flushing. I kept the line in my example for purposes of explicitly stating the desired behavior.

基本主要编程：

class Program
{
    static void Main(string[] args)
    {
        ILog log = LogManager.GetLogger(typeof(Program));
        XmlConfigurator.Configure(new FileInfo(@"C:\temp\logTest.config"));

        string msg;
        while ((msg = Console.ReadLine()) != "Done")
        {
            log.Error(msg);
        }

        LogManager.Shutdown();
    }
}

log prog引用的logTest.config：

logTest.config referenced by main prog:

<log4net>
    <appender name="RollingErrorFileAppender" type="log4net.Appender.RollingFileAppender">
        <param name="File" value="C:\temp\log" />
        <param name="AppendToFile" value="true" />
        <param name="DatePattern" value="_yyyyMMddHH&quot;.log&quot;" />
        <param name="RollingStyle" value="Date" />
        <param name="StaticLogFileName" value="false" />
        <param name="ImmediateFlush" value="true" />
        <filter type="log4net.Filter.LevelRangeFilter">
            <param name="LevelMin" value="ERROR" />
            <param name="LevelMax" value="FATAL" />
        </filter>
        <layout type="log4net.Layout.PatternLayout">
            <param name="ConversionPattern" value="%utcdate{yyyy-MM-dd HH:mm:ss.fff},[%thread],%level,%logger,%m%n"/>
        </layout>
    </appender>
    <root>
        <level value="INFO" />
        <appender-ref ref="RollingErrorFileAppender" />
    </root>
</log4net>

这篇关于Log4Net RollingFileAppender没有使用低容量日志刷新IO缓冲区的文章就介绍到这了，希望我们推荐的答案对大家有所帮助，也希望大家多多支持IT屋！