Serilog останавливает протоколирование событий

#serilog

#serilog

Вопрос:

Я создал приемник Serilog, который взаимодействует с веб-службой, которая сохраняет сообщения журнала в базе данных. Это работает большую часть времени. Даже в тех случаях, когда возникает исключение, вызывающее веб-службу, она будет регистрироваться в файле Selflog. Однако, однако, периодически он просто перестает регистрироваться либо в нашей пользовательской веб-службе, либо в файле журнала self, и после прекращения регистрации он никогда не начинает регистрироваться где-либо еще. Это выполняется в службе Windows, и я должен остановить и перезапустить службу Windows, прежде чем она снова начнет протоколирование. Типичное исключение, которое я могу получить от вызова веб-службы: «Задача была отменена». Это может быть вызвано тем, что веб-сервис не отвечает в течение настроенного периода ожидания. Как я уже сказал, обычно он правильно записывает события в файл selflog. Только периодически он просто перестает регистрироваться везде. Я также должен сказать, что объем генерируемых журналов очень высок.

Это проект dnx, и здесь приведена часть файла project.json:

   "dependencies": {
    "Newtonsoft.Json": "8.0.2",
    "Serilog.Sinks.PeriodicBatching": "2.0.0",
    "Serilog": "2.0.0-beta-465",
    "Serilog.Extensions.Logging": "1.0.0-rc1-final-10092",
    "JA.AppCentral.Logging.Contracts": "0.1.0-alpha1-*",
    "FluentAssertions": "4.2.2",
    "Microsoft.Extensions.Configuration": "1.0.0-rc1-final",
    "Microsoft.AspNet.WebApi.Client": "4.0.30506"
  }
  

Я включил соответствующие части класса приемника. Он наследуется от периодического приемника пакетной обработки.

Код, используемый для настройки Selflog, следующий:

     FileStream fs = new FileStream(selfLogFilePath, fileMode, FileAccess.Write);
    StreamWriter sw = new StreamWriter(fs);
    Serilog.Debugging.SelfLog.Out = TextWriter.Synchronized(sw);
  

Вот код приемника: enter code here

 using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;

using Serilog;
using System.Net.Http;
using Serilog.Core;
using Serilog.Events;
using System.Net.Http.Headers;
using System.IO;
using Serilog.Formatting.Json;
using Serilog.Debugging;
using Newtonsoft.Json;
using JA.AppCentral.Logging.Contracts;
using Microsoft.Extensions.Configuration;
using Serilog.Sinks.PeriodicBatching;
using System.Diagnostics;
using System.Threading;

namespace JA.AppCentral.Logging

{

    public class AppCentralSink: Serilog.Sinks.PeriodicBatching.PeriodicBatchingSink
    {
        readonly HttpClient _httpClient;
        LoggingLevelSwitch _levelControlSwitch;
        const string BulkAddUri = "api/appLogging/bulkAdd";
        private Uri _baseUri;
        private string _baseUriPath;
        readonly long? _eventBodyLimitBytes = 1000000;
        static readonly TimeSpan RequiredLevelCheckInterval = TimeSpan.FromSeconds(10);
        private TimeSpan _timeout = TimeSpan.FromMinutes(1);
        private bool _saveMessageTemplate;
        private int eventsCount;
        private LoggingRepositoryServiceResponse _logServiceResponse;
        private int _totalInsertedRecords;
        public event EventHandler<ResponseEventArgs> ResponseReceived = delegate { };

        DateTime _nextRequiredLevelCheckUtc = DateTime.Now.Add(RequiredLevelCheckInterval);

        private int osId;
        private string server;
        private string username;
        private int threadId;
        private string appcode;


        /// <summary>
        /// Overloaded constructor, to pass AppSettings via IConfiguration , instead of separate parameters
        /// </summary>
        /// <param name="config"></param>
        public AppCentralSink(IConfiguration config)
                : base(Convert.ToInt32(GetConfigParams(config)["BatchSizeLimit"]), 
                      TimeSpan.FromSeconds(Convert.ToDouble(GetConfigParams(config)["BatchEmitIntervalSeconds"])))
        {
            Dictionary<string, string> appSettingDict = GetConfigParams(config);
            long tempLongVal;
            long? eventBodyLimitBytes = long.TryParse(appSettingDict["EventBodyMaxSizeBytes"], out tempLongVal) ? tempLongVal : (long?)null;
            if (eventBodyLimitBytes != null)
                _eventBodyLimitBytes = eventBodyLimitBytes;

            bool saveMessageTemplate = Convert.ToBoolean(appSettingDict["LogMessageTemplate"]);
            if (saveMessageTemplate != false)
                _saveMessageTemplate = saveMessageTemplate;

            string serverUrl = appSettingDict["Url"];
            //baseUri = "http://localhost:49774/"; 

            if (!serverUrl.EndsWith("/"))
                serverUrl  = "/";
            _baseUriPath = serverUrl;
            _baseUri = new Uri(serverUrl);

            TimeSpan timeout = TimeSpan.FromSeconds(Convert.ToDouble(appSettingDict["WebRequestTimeoutSeconds"]));
            if (timeout != default(TimeSpan))
                _timeout = timeout;

            //Default Authentication via http client handler
            HttpClientHandler handler = new HttpClientHandler()
            {
                PreAuthenticate = true,
                UseDefaultCredentials = true
            };

            _httpClient = new HttpClient(handler);
            _httpClient.BaseAddress = _baseUri;
            _httpClient.DefaultRequestHeaders.Accept.Clear();
            _httpClient.DefaultRequestHeaders.Accept.Add(new MediaTypeWithQualityHeaderValue("application/json"));
            _httpClient.Timeout = _timeout;

            //Init Context properties
            OsId = Process.GetCurrentProcess().Id;
            Server = Environment.MachineName;
            Username = Environment.UserName;
            ThreadId = Thread.CurrentThread.ManagedThreadId;
            Appcode = config["JA:AppCatalog:AppCode"];

        }


        private static Dictionary<string,string> GetConfigParams(IConfiguration config)
        {
            Dictionary<string, string> appSettings = new Dictionary<string, string>();

            var SerilogSection = config.GetSection("AppCentralLogging");
            appSettings.Add("Url", SerilogSection["Url"]);
            appSettings.Add("BatchSizeLimit", SerilogSection["BatchSizeLimit"]);
            appSettings.Add("BatchEmitIntervalSeconds", SerilogSection["BatchEmitIntervalSeconds"]);
            appSettings.Add("EventBodyMaxSizeBytes", SerilogSection["EventBodyMaxSizeBytes"]);
            appSettings.Add("LogMessageTemplate", SerilogSection["LogMessageTemplate"]);
            appSettings.Add("WebRequestTimeoutSeconds", SerilogSection["WebRequestTimeoutSeconds"]);

            appSettings.Add("SelfLogFileLocationAndPrefix", config["Serilog:SelfLogFileLocationAndPrefix"]);

            return appSettings;
        }

        // The sink must emit at least one event on startup, and the server be
        // configured to set a specific level, before background level checks will be performed.
        protected override void OnEmptyBatch()
        {
            if (_levelControlSwitch != null amp;amp;
                _nextRequiredLevelCheckUtc < DateTime.Now)
            {
                EmitBatch(Enumerable.Empty<LogEvent>());
            }
        }


        protected override async Task EmitBatchAsync(IEnumerable<LogEvent> events)
        {
            _nextRequiredLevelCheckUtc = DateTime.Now.Add(RequiredLevelCheckInterval);

            var formatter = new JsonFormatter();
            List<LogEntry> logEntriesList = new List<LogEntry>();
            try
            {
                foreach (var logEvent in events)
                {
                    EventsCount  ;
                    LogEntry jaLogEvent = ConvertToLogEntry(logEvent);

                    if (_eventBodyLimitBytes.HasValue)
                    {
                        var scratch = new StringWriter();
                        formatter.Format(logEvent, scratch);
                        var buffered = scratch.ToString();

                        if (Encoding.UTF8.GetByteCount(buffered) > _eventBodyLimitBytes.Value)
                        {
                            SelfLog.WriteLine("Event JSON representation exceeds the byte size limit of {0} set for this sink and will be dropped; data: {1}", _eventBodyLimitBytes, buffered);
                        }
                        else
                        {
                            logEntriesList.Add(jaLogEvent);
                        }
                    }
                    else
                    {
                        logEntriesList.Add(jaLogEvent);
                    }
                }

                var result = await _httpClient.PostAsJsonAsync(BulkAddUri, logEntriesList);


                if (!result.IsSuccessStatusCode)
                {
                    try
                    {
                        var error = await result.Content.ReadAsStringAsync();
                        var responseExcep = new Exception(error);
                        throw responseExcep;
                    }
                    catch (Exception e)
                    {
                        SelfLog.WriteLine("FailedEvents: "   GetEventsAsString(events));
                        throw new Exception("Error calling Logging Web Service: status code: "   result.StatusCode  
                                   " reason: "   result.ReasonPhrase   " excep: "   e.ToString());
                    }
                }
                _logServiceResponse = await result.Content.ReadAsAsync<LoggingRepositoryServiceResponse>();
                if (_logServiceResponse.ResponseException != null)
                {
                    SelfLog.WriteLine("FailedEvents: "   GetEventsAsString(events));
                    SelfLog.WriteLine(_logServiceResponse.ResponseMessage);
                    throw new Exception("Error calling Logging Web Service: "  
                                    _logServiceResponse.ResponseMessage);
                }
                _totalInsertedRecords = _totalInsertedRecords   _logServiceResponse.NumRecordsInserted;
                ResponseReceived(this, new ResponseEventArgs(result));

            }
            catch (Exception e)
            {
                    SelfLog.WriteLine("Error processing log batch, excep: "   e.ToString());
                    SelfLogEvents(events);
                    throw;
            }
        }


        private void SelfLogEvents(IEnumerable<LogEvent> events)
        {
            SelfLog.WriteLine("Failed to write following log events:");
            foreach (var e in events)
            {
                SelfLog.WriteLine($"  Event: "   e.RenderMessage());
            }
        }

        private string GetEventsAsString(IEnumerable<LogEvent> events)
        {
            string eventsResult = string.Empty;
            foreach(LogEvent le in events)
            {
                eventsResult  = "["   le.RenderMessage()   "]";
            }

            return eventsResu<
        }

        private LogEntry ConvertToLogEntry(LogEvent logEvent)
        {
            string propertiesString = JsonConvert.SerializeObject(logEvent.Properties);
            string messageTemplate = _saveMessageTemplate == true ? logEvent.MessageTemplate.Text : string.Empty;

            //Append Exception to the message if it's not null
            string logEventMessage = logEvent.RenderMessage();
            if (logEvent.Exception != null)
            {
                logEventMessage = logEventMessage   " Exception: "   logEvent.Exception.ToString();
            }

            LogEntry logEntry = new LogEntry("AppCode", "Action", logEvent.Level.ToString(), messageTemplate,
                                                        logEventMessage, propertiesString,
                                                        logEvent.Timestamp);
            //Append additional properties
            if (String.IsNullOrEmpty(Appcode))
            {
                logEntry.AppCode = logEvent.Properties.Keys.Contains("appcode") ? logEvent.Properties["appcode"].ToString().Replace(""", "") : string.Empty;                
                logEntry.OsPId = logEvent.Properties.Keys.Contains("os_pid") ? logEvent.Properties["os_pid"].ToString().Replace(""", "") : string.Empty;
                logEntry.ThreadId = logEvent.Properties.Keys.Contains("thread_id") ? logEvent.Properties["thread_id"].ToString().Replace(""", "") : string.Empty;
                logEntry.Server = logEvent.Properties.Keys.Contains("server") ? logEvent.Properties["server"].ToString().Replace(""", "") : string.Empty;
                logEntry.Username = logEvent.Properties.Keys.Contains("username") ? logEvent.Properties["username"].ToString().Replace(""", "") : string.Empty;
            }
            else
            {
                logEntry.AppCode = Appcode;
                logEntry.OsPId = OsId.ToString();
                logEntry.ThreadId = ThreadId.ToString();
                logEntry.Server = Server;
                logEntry.Username = Username;

            }

            logEntry.SessionId = logEvent.Properties.Keys.Contains("session_id") ? logEvent.Properties["session_id"].ToString().Replace(""", "") : string.Empty;
            logEntry.Action = logEvent.Properties.Keys.Contains("action") ? logEvent.Properties["action"].ToString().Replace(""", "") : string.Empty;

            //Append SourceContext
            //Append SourceContext
            LogEventPropertyValue propertyValue;
            if (logEvent.Properties.TryGetValue("SourceContext", out propertyValue))
            {
                logEntry.SourceContext = propertyValue.ToString().Trim(new[] { '"' });
            }


            return logEntry;
        }


        public int EventsCount
        {
            get
            {
                return eventsCount;
            }

            set
            {
                eventsCount = value;
            }
        }

        public LoggingRepositoryServiceResponse LogServiceResponse
        {
            get
            {
                return _logServiceResponse;
            }

            set
            {
                _logServiceResponse = value;
            }
        }

        public int TotalInsertedRecords
        {
            get
            {
                return _totalInsertedRecords;
            }

            set
            {
                _totalInsertedRecords = value;
            }
        }

        protected override void Dispose(bool disposing)
        {
            base.Dispose(disposing);

            if (disposing)
                _httpClient.Dispose();
        }

        public HttpClient HttpClient
        {
            get { return _httpClient; }
        }

    }

    public class ResponseEventArgs : EventArgs
    {
        public ResponseEventArgs(HttpResponseMessage response)
        {
            Response = response;
        }

        public HttpResponseMessage Response { get; }
    }
}
  

Комментарии:

1. PeriodicBatchingSink будет экспоненциально отключаться, если выдается ошибка EmitBatchAsync() — продолжительность зависит от периода пакетной обработки, поэтому она может приостановиться на некоторое время.

2. Кроме того, любая причина не обновлять Serilog и Serilog. Расширения. Запись в RTM-версии?

3. спасибо за ваш ответ. Я просмотрел код periodicbatchsink и увидел, как он отступает при возникновении ошибок. Я также видел, что при использовании ограниченной очереди и заполнении очереди она выдает ошибку. Я должен думать, что это должно самозаписываться.