0
我們對於我們的日誌有這種奇怪的行爲。我們正在使用log4net的，這裏是我們的配置：由於FileSystemWatcher Log4net沒有顯示日誌的正確順序
<?xml version="1.0" encoding="utf-8"?>
<configuration>
<configSections>
<section name="log4net" type="System.Configuration.IgnoreSectionHandler" />
</configSections>
<log4net>
<appender name="LogAppenderinfo" type="log4net.Appender.RollingFileAppender">
<file value="..\log\filename.log" />
<appendToFile value="true" />
<maxSizeRollBackups value="0" />
<maximumFileSize value="10MB" />
<rollingStyle value="Size" />
<staticLogFileName value="true" />
<lockingmodel type="log4net.Appender.FileAppender+MinimalLock"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date{MMM dd HH:mm:ss,fffffff}|: %message%newline%exception" />
</layout>
</appender>
<root>
<level value="ALL" />
</root>
<logger name = "filename.log">
<level value="ALL" />
<appender-ref ref="LogAppenderinfo" />
</logger>
</log4net>
</configuration>
這是我們的，我們如何使用它在我們的代碼示例：
internal static ILog logm = LogManager.GetLogger("filename.log");
public void WebServerFunction()
{
logm.DebugFormat("INFO |Web server call WebServerFunction for: {0}", param);
logm.DebugFormat("START | WebServerFunction started for: {0}", param);
//some code here then another logging in the end of the function call
logm.DebugFormat("FINISH | WebServerFunction finished for: {0}", param);
}
現在，這裏是內部filename.log樣本輸出日誌：
Nov 22 17:31:25,6183343|: INFO |Web server call WebServerFunction for: NET_10.10.11.0_24
Nov 22 17:31:25,6183343|: FINISH | WebServerFunction finished for: NET_10.10.11.0_24
Nov 22 17:31:27,6331853|: INFO |Web server call WebServerFunction for: NET_10.10.11.0_24
Nov 22 17:31:27,6488043|: START | WebServerFunction started for: NET_10.10.11.0_24
Nov 22 17:31:27,6488043|: FINISH | WebServerFunction finished for: NET_10.10.11.0_24
正如你可以從前兩行看到的那樣，在INFO被記錄之後，下一行是FINISH，它跳過了START。然後對於下一行START將顯示其相應的順序，但有時它不會。 INFO將始終顯示，但START和FINISH有時不會顯示相應的順序。那麼可能是什麼原因呢？
這是基於什麼斯特凡回答更新的輸出...
Nov 24 12:59:45,2113366|11 : INFO |Web server call WebServerFunction() for: NET_10.191.20.0_24
Nov 24 12:59:45,2113366|11 : START | WebServerFunction started for: NET_10.191.20.0_24
Nov 24 12:59:45,2113366|11 : FINISH | WebServerFunction finished for: NET_10.191.20.0_24
Nov 24 12:59:47,2268842|11 : INFO |Web server call WebServerFunction() for: NET_10.191.20.0_24
Nov 24 12:59:47,2268842|11 : FINISH | WebServerFunction finished for: NET_10.191.20.0_24
Nov 24 12:59:47,2425086|11 : INFO |Web server call WebServerFunction() for: NET_10.191.20.0_24
Nov 24 12:59:47,2425086|11 : FINISH | WebServerFunction finished for: NET_10.191.20.0_24
Nov 24 12:59:49,2580562|11 : INFO |Web server call WebServerFunction() for: NET_10.191.20.0_24
Nov 24 12:59:49,2736806|11 : FINISH | WebServerFunction finished for: NET_10.191.20.0_24
正如你所看到的，只有一個線程工作......不過開局並不記錄但INFO和光潔度一致已記錄...順便說一句，信息和開始只是相鄰的聲明，彼此也注意他們的時間，信息和完成記錄在同一時間，而開始沒有記錄在那段時間...
希望你能推薦更多的想法在這一個...
第二次更新： 我們終於pinp ointed原因爲這一個，爲什麼有些日誌還沒有登錄的原因是因爲這只是聽相同的登錄我們的Web服務功能正在寫FileSystemWatcher的的...
下面是代碼：
watcher = new FileSystemWatcher(logDirectory, FileName)
{
NotifyFilter = NotifyFilters.LastWrite /*| NotifyFilters.LastAccess | NotifyFilters.Size*/
};
watcher.Changed += OnFileSystemChanged;
watcher.EnableRaisingEvents = true;
對於OnFileSystemChanged：
private static void OnFileSystemChanged(object source, FileSystemEventArgs e)
{
try
{
if (e.ChangeType == WatcherChangeTypes.Changed)
{
var data = ReadFromFileWithRetries(e.FullPath);
if (data != null && data != _prevData)
{
if (data.Length > _prevData.Length)
{
_prevData = data.Remove(0, _prevData.Length);
}
Console.WriteLine(_prevData);
_prevData = data;
}
}
}
catch (Exception exception)
{
var msg = exception.Message;
}
}
那麼它基本上只是聽日誌文件，然後寫入日誌的輸出...有什麼辦法，這些記錄將不介入FileSystemWatcher的記錄有序Web服務器的日誌記錄冰？
我從來沒有見過這樣的事情。那裏的註釋表明還有更多的代碼被省略了，這讓我想知道在代碼中你實際上是否正在執行，也許在信息消息和啓動消息之間有一些東西可能會在某些情況下使它錯過啓動消息線。我建議再看一下，然後嘗試按照問題中的描述來運行代碼（如果那還不是你正在做的）並且看看你是否得到了不同的結果。 –
嗨戴夫。我們做了一個簡單的原型，它直接調用我們的Web服務函數並讓Web服務函數調用日誌。令人驚訝的是，結果是正確的。事實上，調用日誌的順序是正確的。但在我們的（工具）日誌中的web服務被跳過... –