Мы используем NLog 4.7.2 в приложении ASP. NET WebAPI, работающем на Windows Server 2016 с полной загрузкой. NET Framework v4.8. Я настроил параметры архива таким образом, что, как мне кажется, предполагается, что журналы будут медленно катиться в течение дня, когда их размер достигает 1 ГБ. При нашей загрузке это должно создать, возможно, один или два файла журнала. Вместо этого я вижу, что файлы журналов архивируются быстро в непредсказуемое время от 300 до 600 раз в день, иногда каждые несколько минут, с непредсказуемыми размерами от 1 КБ до 32 917 КБ.
Используя настройки ниже, я просматриваю наши журналы папку и увидеть сотни файлов:
My-Log-File.20200713.0
My-Log-File.20200713.1
:
My-Log-File.20200713.365
My-Log-File.log
Вот основные параметры настроек, которые мы используем в Nlog.config:
<?xml version="1.0"?>
<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
autoReload="true"
internalLogLevel="Info"
internalLogFile="C:\Logs\nlog-internal.log">
<extensions>
<add assembly="MyApp.Common.Web"/> <!-- adds the context-properties renderer -->
</extensions>
<targets async="true">
<target
name="logFile"
xsi:type="File"
layout="${longdate:universalTime=true}Z ${pad:padding=-7:inner=[${level:uppercase=true}]} [${machinename}] ${pad:padding=-5:inner=[${threadid}]} [${logger}] [${context-properties}] ${message} ${onexception:${exception:format=ToString}}"
fileName="C:\Logs\My-Log-File.log"
maxArchiveDays="2"
archiveAboveSize="1000000000"
archiveFileName="C:\Logs\My-Log-File.{#}.log"
archiveEvery="Day"
archiveNumbering="DateAndSequence"
archiveDateFormat="yyyyMMdd"
concurrentWrites="false"
encoding="utf-8" />
</targets>
<rules>
<!-- many rules here (omitted for clarity) -->
<logger name="*" minlevel="Info" writeTo="logFile" />
</rules>
</nlog>
Внутренний журнал не очень помогает, нет регистрируются ошибки, просто архивирование в случайное время
2020-07-14 15:34:31.0322 Info Message Template Auto Format enabled
2020-07-14 15:34:31.0478 Info Loading assembly: MyApp.Common.Web
2020-07-14 15:34:31.1103 Info Adding target AsyncTargetWrapper(Name=logFile)
2020-07-14 15:34:31.1572 Info Validating config: TargetNames=logFile, ConfigItems=61, FilePath=C:\inetpub\wwwroot\NLog.config
2020-07-14 15:34:31.1885 Info Configuration initialized.
2020-07-14 15:34:31.2041 Info NLog, Version=4.0.0.0, Culture=neutral, PublicKeyToken=5120e14c03d0593c. File version: 4.7.2.11786. Product version: 4.7.2+024896f64b840a743d3fd89e29c2186681e7795f. GlobalAssemblyCache: False
2020-07-14 15:36:35.6895 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200714.179.log
2020-07-14 15:41:34.0223 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200714.180.log
2020-07-14 15:46:14.8703 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200714.181.log
Я включил ведение журнала отладки, и, похоже, это не говорит мне больше о том, почему архивируется так часто:
2020-08-03 22:06:36.8157 Debug FileAppender Closing Invalidate - C:\Logs\My-Log-File.log
2020-08-03 22:06:36.8157 Debug FileTarget(Name=logFile_wrapped): Archive mutex not available: C:\Logs\My-Log-File.log
2020-08-03 22:06:36.8157 Debug FileTarget(Name=logFile_wrapped): Do archive file: 'C:\Logs\My-Log-File.log'
2020-08-03 22:06:36.8157 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200803.426.log
2020-08-03 22:06:36.8157 Debug FileTarget(Name=logFile_wrapped): Move file from 'C:\Logs\My-Log-File.log' to 'C:\Logs\My-Log-File.20200803.426.log'
2020-08-03 22:06:36.8157 Debug FileTarget(Name=logFile_wrapped): Preparing for new file 'C:\Logs\My-Log-File.log'
2020-08-03 22:06:36.8157 Debug Creating file appender: C:\Logs\My-Log-File.log
2020-08-03 22:10:12.9027 Debug FileAppender Closing Invalidate - C:\Logs\My-Log-File.log
2020-08-03 22:10:12.9027 Debug FileTarget(Name=logFile_wrapped): Archive mutex not available: C:\Logs\My-Log-File.log
2020-08-03 22:10:12.9027 Debug FileTarget(Name=logFile_wrapped): Do archive file: 'C:\Logs\My-Log-File.log'
2020-08-03 22:10:12.9027 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200803.427.log
2020-08-03 22:10:12.9027 Debug FileTarget(Name=logFile_wrapped): Move file from 'C:\Logs\My-Log-File.log' to 'C:\Logs\My-Log-File.20200803.427.log'
2020-08-03 22:10:12.9027 Debug FileTarget(Name=logFile_wrapped): Preparing for new file 'C:\Logs\My-Log-File.log'
2020-08-03 22:10:12.9027 Debug Creating file appender: C:\Logs\My-Log-File.log
I обновили частную сборку NLog с улучшенным протоколированием процесса архивирования по запросу @RolfKristensen, и вот результат:
2020-08-05 13:50:24.3516 Debug FileTarget(Name=logFile_wrapped): Start archiving 'C:\Logs\My-Log-File.log' because FileCreatedTime=20200805 is older than now 20200804
2020-08-05 13:50:24.3516 Debug FileAppender Closing Invalidate - C:\Logs\My-Log-File.log
2020-08-05 13:50:24.3516 Debug FileTarget(Name=logFile_wrapped): Start archiving 'C:\Logs\My-Log-File.log' because FileCreatedTime=20200805 is older than now 20200804
2020-08-05 13:50:24.3516 Debug FileTarget(Name=logFile_wrapped): Do archive file: 'C:\Logs\My-Log-File.log'
2020-08-05 13:50:24.3672 Info FileTarget(Name=logFile_wrapped): Archiving C:\Logs\My-Log-File.log to C:\Logs\My-Log-File.20200805.196.log
2020-08-05 13:50:24.3672 Debug FileTarget(Name=logFile_wrapped): Move file from 'C:\Logs\My-Log-File.log' to 'C:\Logs\My-Log-File.20200805.196.log'
2020-08-05 13:50:24.3672 Debug FileTarget(Name=logFile_wrapped): Preparing for new file 'C:\Logs\My-Log-File.log'
2020-08-05 13:50:24.3672 Debug Creating file appender: C:\Logs\My-Log-File.log
Есть идеи, что здесь происходит? На данный момент это не большая проблема для нас, потому что мы пересылаем эти журналы в Splunk, но я все же хотел бы понять, что происходит.