NLog не выводит sh всех записей журнала при выходе из процесса - PullRequest
0 голосов
/ 16 января 2020

В этой теме - Должен ли NLog flu sh все сообщения в очереди в AsyncTargetWrapper при вызове Flu sh ()? - я читал, что «LogManager устанавливает для конфигурации значение null на выгрузка домена или выход из процесса »(см. раздел« Правка »в первом ответе). В моем понимании это должно привести к тому, что все ожидающие записи журнала будут записаны в зарегистрированные цели. Однако после тестирования с FileTarget, обернутым с AsyncTargetWrapper, это не выполняется. Я создал минимальное репро на GitHub - https://github.com/PaloMraz/NLogMultiProcessTargetsSample, который работает следующим образом:

LogLib - это .netstandard2.0 библиотека, ссылающаяся на NLog 4.6.8 пакет NuGet и разоблачение класс CompositeLogger, который программно настраивает цели NLog:

public class CompositeLogger
{
  private readonly ILogger _logger;

  public CompositeLogger(string logFilePath)
  {
    var fileTarget = new FileTarget("file")
    {
      FileName = logFilePath,
      AutoFlush = true
    };
    var asyncTargetWrapper = new AsyncTargetWrapper("async", fileTarget)
    {
      OverflowAction = AsyncTargetWrapperOverflowAction.Discard
    };

    var config = new LoggingConfiguration();
    config.AddTarget(asyncTargetWrapper);
    config.AddRuleForAllLevels(asyncTargetWrapper);
    LogManager.Configuration = config;

    this._logger = LogManager.GetLogger("Default");
  }

  public void Log(string message) => this._logger.Trace(message);
}

LogConsoleRunner - это консольное приложение. NET Framework 4.8, которое использует LogLib.CompositeLogger для записи указанного количества сообщений журнала в файл (указанный в качестве аргумента командной строки) с небольшой задержкой между операциями записи:

public static class Program
{
  public const int LogWritesCount = 10;
  public static readonly TimeSpan DelayBetweenLogWrites = TimeSpan.FromMilliseconds(25);

  static async Task Main(string[] args)
  {
    string logFilePath = args.FirstOrDefault();
    if (string.IsNullOrWhiteSpace(logFilePath))
    {
      throw new InvalidOperationException("Must specify logging file path as an argument.");
    }

    logFilePath = Path.GetFullPath(logFilePath);
    Process currentProcess = Process.GetCurrentProcess();
    var logger = new CompositeLogger(logFilePath);
    for(int i = 0; i < LogWritesCount; i++)
    {
      logger.Log($"Message from {currentProcess.ProcessName}#{currentProcess.Id} at {DateTimeOffset.Now:O}");
      await Task.Delay(DelayBetweenLogWrites);
    }
  }
}

Наконец, LogTest - это XUnit тестовая сборка с одним тестом, запускающим десять LogConsoleRunner записей, записывающих в одну и ту же файл журнала:

[Fact]
public async Task LaunchMultipleRunners()
{
  string logFilePath = Path.GetTempFileName();
  using var ensureLogFileDisposed = new Nito.Disposables.AnonymousDisposable(() => File.Delete(logFilePath));

  string logConsoleRunnerAppExePath = Path.GetFullPath(
    Path.Combine(
      Path.GetDirectoryName(this.GetType().Assembly.Location),
      @"..\..\..\..\LogConsoleRunner\bin\Debug\LogConsoleRunner.exe"));      
  var startInfo = new ProcessStartInfo(logConsoleRunnerAppExePath)
  {
    Arguments = logFilePath,
    UseShellExecute = false
  };
  const int LaunchProcessCount = 10;
  Process[] processes = Enumerable
    .Range(0, LaunchProcessCount)
    .Select(i => Process.Start(startInfo))
    .ToArray();
  while (!processes.All(p => p.HasExited))
  {
    await Task.Delay(LogConsoleRunner.Program.DelayBetweenLogWrites);
  }

  string[] lines = File.ReadAllLines(logFilePath);
  Assert.Equal(LaunchProcessCount * LogConsoleRunner.Program.LogWritesCount, lines.Length);
}

Ошибка Assert.Equal в последней строке всегда завершается ошибкой, поскольку в целевом файле всегда записывается меньше строк, чем ожидаемое число, равное 100. На моем компьютере оно меняется при каждом запуске между 96 - 99, но никогда не содержит все 100 строк.

Мой вопрос: как мне настроить NLog, чтобы после завершения всех процессов все ожидающие записи журнала записывались в целевой файл журнала? * 1 034 *

Ответы [ 2 ]

2 голосов
/ 16 января 2020

Просто позвоните LogManager.Shutdown() в конце вашего Main. Это сделает грипп sh всех ожидающих logevents. Подробнее .

Примечание: если вам нужен NLog после гриппа sh, тогда вместо выключения вы можете использовать LogManager.Flush().

1 голос
/ 17 января 2020

Посмотрел ваш пример кода, и у вас есть несколько процессов, записывающих одно и то же имя файла.

Думаю, вы жертва компромисса между производительностью и правильностью.

Когда несколько процессов одновременно записывают в один и тот же файл, необходима некоторая блокировка для координации. По умолчанию NLog использует наиболее совместимый режим (KeepFileOpen = false), который заключается в блокировке файлов из операционной системы (работает для большинства платформ).

Блокировка файлов из операционной системы не справедлива и не масштабируется при наличии более 2 процессов записывают в один файл. Исключения будут выдаваться, когда один процесс попытается открыть файл, который в данный момент используется другим процессом.

NLog пытается обработать это исключение, повторяя попытку ошибки (concurrentWriteAttempts = 10) вместе со случайным выбором времени ожидания до повторной попытки. Это нормально работает для 2 процессов, но когда вы начинаете увеличивать количество процессов, это увеличивает вероятность того, что один процесс будет неудачным 10 раз подряд. После последней попытки NLog сбрасывает LogEvent (вероятно, то, что вы видите).

KeepFileOpen = false медленно (300 записей / се c), и в сочетании с retry-logi c затем он становится чрезвычайно медленным Но при использовании AsyncWrapper, когда вы разрешаете пакетную обработку, это в значительной степени устраняет снижение производительности. Но теперь весь пакет может быть потерян, когда количество повторов истекло.

Вместо того, чтобы полагаться на блокировки файлов операционной системы, вы можете вместо этого полагаться на NLog, выполняющий межпроцессное взаимодействие с использованием глобального мьютекса. Этот режим активируется с KeepFileOpen=True и ConcurrentWrites=true. Вместо 300 записей / se c, тогда он становится 100.000 записей / se c, и механизм блокировки более справедлив, поэтому нет необходимости повторять попытки. Не все платформы поддерживают этот режим, но должны прекрасно работать на NET 4,8 на Windows (и NetCore2 на Linux).

См. Также: https://github.com/NLog/NLog/wiki/File-target#Multi -processes-writing- тот же файл

Добро пожаловать на сайт PullRequest, где вы можете задавать вопросы и получать ответы от других членов сообщества.
...