Писать в файл c лог
Ведение логов помогает разработчику в процессе создания и последующего сопровождения приложения, при поиске ошибок в коде и в разрешении непонятных ситуаций, когда наше приложение в момент работы ведет себя странным образом, и нам нужно найти причину такого поведения.
Любой разработчик сталкивается с подобными ситуациями, когда какой-то компонент приложения отрабатывает странным образом, выдает не тот результат или вообще перестает работать. Использование логов поможет нам в подобных ситуациях. Время поиска проблемных мест в нашем коде сократится в разы, и мы быстрее сможем решить ту или иную проблему.
Вообще, на сегодняшний момент ни одно более или менее серьезное приложение не обходится без написания логов.
Лог (log) - это специальный журнал, в котором хранится информация о состоянии работы приложения (программы).
Под таким журналом можно понимать и записи в обычный текстовый файл, и записи в базу данных, и записи на удаленный веб-сервис, и даже email-письма на определенный адрес о тех или иных состояниях нашего приложения.
Какие записи делать в этот журнал, то есть, какую конкретно информацию записывать, определяет сам разработчик. Это могут быть сведения о том, что все работает в штатном режиме, то есть просто ежедневный мониторинг нашего приложения, или что произошла какая-то ошибка, на которую нужно максимально срочно отреагировать и устранить, и так далее.
Trace – максимально детальная информация о том, что происходит с целевым участком кода, по шагам. Например: Попытка открыть подключение к БД, успешно\неуспешно. Сколько времени заняла эта операция. Сколько времени выполнялась выборка из БД, успешно\неуспешно. Сколько записей извлечено. Какая была нагрузка на систему, сколько использовано памяти. Сколько записей прошло нужную фильтрацию. Сколько записей оказалось в результирующей выборке, куда эти записи отправились дальше. Проверка нужных значений в каждой записи.
Debug – это информация для отладки. Логирование крупных операций, менее детально, чем в Trace. Здесь мы не так подробно описываем весь процесс операции, но, тем не менее, заносим в журнал основные операции. Например: Совершено обращение к БД. Из базы выбрано N записей. Записи успешно обработаны и отправлены клиенту.
Если же в опасных участках кода мы генерируем исключение, то теперь мы также добавим запись в лог с пометкой Error.
Иногда разработчики ленятся писать логи, не хотят тратить на это время. В дальнейшем оказывается, что время, затраченное на поиск и исправление ошибок, в разы больше времени, которое потребовалось бы на создание системы логов.
Для того, чтобы начать логирование, мы подключим в наш проект платформу NLog. Это можно легко сделать посредством менеджера NuGet (прямо из Visual Studio).
Обратите внимание на конфигурационный файл NLog.config. В этом файле находятся настройки логгера (куда будут выводиться логи, формат записи логов и т.д.). Давайте настроим файл следующим образом:
Здесь мы описали два правила и цели, к которым они применяются. Мы хотим чтобы отладочная информация была записана в один файл, а информация об ошибках - в другой (в поддиректории errors). Оба лога будут писаться в текстовый файл. Также мы используем специальные теги (директивы), которые понимает NLog. На их место будут подставлены соответствующие значения в процессе выполнения. Опишем теги, которые используются у нас в конфигурации (описание всех тегов и любую другую информацию можно найти на официальном сайте проекта NLog):
Далее уже в коде объявим новый логгер (здесь код проекта приводится в сокращенном виде, исходный код всего проекта можно скачать в конце статьи):
Чаще всего следует объявлять один статичный логгер в пределах всего класса. Здесь мы посредством класса-менеджера LogManager объявили новый логгер, с которым будем работать.
Начнем логирование с уровня Trace. В методе, где мы выбираем студента по его идентификатору, давайте максимально подробно опишем как это происходит:
Теперь определим, что же нам записать на уровне Fatal. В нашем простейшем примере просто смоделируем подобную ситуацию:
Мы рассмотрели все шесть уровней логирования и описали процесс работы нашего приложения максимально подробно. Теперь мы можем сразу проанализировать работу сайта, просто изучив логи, и не заглядывать в исходный код.
Подобным образом происходит логирование. В нашем простейшем примере, где мы моделируем работу со студентами, все предельно ясно и прозрачно даже без логов. Но в сложных проектах ведение логов является неотъемлемой частью разработки.
На этом здесь все, давайте подведем небольшой итог. Мы изучили тему логирования в приложении. Посмотрели как правильно логировать те или иные участки кода, а также познакомились с одной из самых популярных платформ логирования – это NLog Platform, также рассмотрели ее возможности и как можно настроить генерацию логов на этой платформе.
Зачем что-то ещё придумывать, подключать внешние библиотеки, настраивать конфиги?
На практике, оказывается, что всё не так: одного лог-файла становится уже недостаточно, возникают проблемы с многопоточностью, форматом логов, записью времени, производительностью итд.
Какие же фичи должен поддерживать хороший логгер?
Фичи добропорядочного логгера
Что и как писать в логи
Уровни логгирования
Что означает каждый уровень?
Правильное определение уровней ошибок сказывается на качестве системы и простоте её сопровождения.
Жизненный пример выбора уровней
Давайте представим, что разрабатываемая система – сотрудник почты, который принимает посылки. Принесли посылку.
Debug: Получена посылка 1. Проверяю размер…
Debug: Размер посылки 1: 40x100
Debug: Взвешиваю посылку…
Debug: Вес посылки 1: 1кг
Debug: Проверяю соответствие нормам…
Info (не Error!): Посылка 1 размером 40x100, весом 1кг, отклонена: превышен максимальный размер
…
Info: Посылка 2 размером 20x60, весом 0.5 кг передана на обработку оператору 1
…
Warn: Отказано в обработке для посылки 3: дата на посылке относится к будущему: 2050-01-01
…
Error: Не удалось отдать посылку оператору: оператор не отвечает: таймаут ожидания ответа оператора
…
Fatal: Произошёл отказ весов. Посылки не будут приниматься до восстановления работоспособности.
Логи и исключения
Они неотделимы друг от друга, как Ленин и партия. Обработка исключительных ситуаций или ошибок очень часто нуждается в правильном логгировании.
Плохой пример:
Не пишите исключения без сопроводительного текста в логи. Увидев ни о чём не говорящий stack trace, лично я прихожу в панику. Что это такое – ошибка, уведомление? Как отреагировала программа на это исключение? Продолжила работу в нормальном режиме, упала, ждёт реакции администратора? К сожалению, часто встречаю такое в коде, что весьма печально. Правильный путь:
Log( "При записи истории комментариев для аккаунта в хранилище произошла ошибка, данные за сегодня не будут доступны: " , account, ex);
КДПВ
Описанное ниже ни в коем случае не tutorial или best practice. Я решил всего лишь агрегировать и задокументировать свои достижения в поставленном вопросе.
Надеюсь, содержимое данной статьи позволит ищущим информацию по логированию почерпнуть что-то новое или принять какое-либо решение. И, само собой, надеюсь получить конструктивный фидбек от сообщества. Это даёт шанс делать что-то лучше.
Для чего? Для кого?
Сохранение некой человекочитаемой информации о позитивном или негативном событии в процессе исполнения программного кода, возможно, с сохранением качественных или количественных показателей и данных в составе сохраняемой информации с привязкой ко времени наступления события.
Сложная вышла формулировка, но в общем случае вполне описывает задачу создания и ведения логов. Качественное записывание логов помогает разработчику контролировать внутреннее состояние кода на любом этапе его жизни: от дебага до инсталляции в неизвестном окружении компьютера потребителя.
Что ж, давайте покажу, как я пишу логи.
Инструментарий
У этой платформы весьма неплохая документация и крайне полезные примеры использования. Естественно, в разное время и для разных проектов я использовал NLog по-разному. Но к какому-то моменту родился код, который теперь используется, как сниппет и практически не изменяется.
Реализация
Некоторые подробности
Голый код, хоть и с комментариями, — это не круто. Поэтому опишу ряд условностей и допущений:
- _settings — некий объект настроек. Не слишком важно, как именно он формируется, но получен он должен быть раньше первой инициализации логгера.
- _logConfig — конфигурация NLog, выполненная не в отдельном файле NLog.config, а прямо в коде.
Собственно, методы в регионе Target Methods и отвечают за создание этих “целей”:
FileTarget — для записи лога в файл.
Про Graylog (немножко)
Описание установки и настройки сервиса в эту статью не войдёт. Скажу только, что развернул его в докере. Это также описано в документации:
Добавлю также пример настройки «Input'а» в Graylog:
Организовав проброс с my.web.adress.domain на порт 12201 своей докер-машины, можно получить доступный отовсюду сбощик логов. Но это факультатив и не всем нужно.
Про GELF
Чтобы отправлять что-либо в формате GELF на некий url потребуется использование дополнительного target'а. Они представлены в разделе Integrations документации.
Специально использовал обобщённый код, чтобы был ясен принцип: «произвольное имя + произвольное значение». Значение может успешно «добываться» каким-нибудь своим методом. Например, чтением сетевых настроек или свободного места на системном диске. Whatever…
Бонус
Бытует мнение (и я его не оспариваю), что логи полезнее всего при отлове ошибок. Конструкции try/catch успешно используются и в большинстве случаев оправдывают себя. Сам «объект ошибки» наполнен отладочной информацией, данными о цепочке событий при её возникновении и другим. Удобно читать подобный объект не всегда получается.
Для себя выработал такое решение:
Поле exeption_json_data — exception, превращённый в json.
Тот же exception, разбитый на поля.
Результат
В итоге применения описанного подхода и разумного внедрения в тело кода вызовов логгера получаем централизованный сбор логов с удобным интерфейсом для их чтения, парсинга, анализа. Имеем удобный инструмент для оповещений об определённых значениях в логах.
Также никуда не деваются привычные log-файлы, которые также можно перечитывать, делать выводы. Это не конкурент и не замена системам мониторинга. Но теперь ситуация «моё приложение работает на 100+ сильно разных компьютерах в 3+ иноязычных странах и вдруг где-то поломалось» решается несколько легче и много быстрее.
Это всё?
В принципе, я рассказал всё, что необходимо для относительно комфортного логирования ваших приложений. Готов обсудить, получить советы.
Спасибо, что прочли. Увидимся в комментариях.
UPD: добавил в работу target'ов AsyncWrapper по совету justmara
Change log levels in a running app
The Logging API doesn't include a scenario to change log levels while an app is running. However, some configuration providers are capable of reloading configuration, which takes immediate effect on logging configuration. For example, the File Configuration Provider reloads logging configuration by default. If configuration is changed in code while an app is running, the app can call IConfigurationRoot.Reload to update the app's logging configuration.
Log level
The following table lists the LogLevel values, the convenience Log extension method, and the suggested usage:
LogLevel | Value | Method | Description |
---|---|---|---|
Trace | 0 | LogTrace | Contain the most detailed messages. These messages may contain sensitive app data. These messages are disabled by default and should not be enabled in production. |
Debug | 1 | LogDebug | For debugging and development. Use with caution in production due to the high volume. |
Information | 2 | LogInformation | Tracks the general flow of the app. May have long-term value. |
Warning | 3 | LogWarning | For abnormal or unexpected events. Typically includes errors or conditions that don't cause the app to fail. |
Error | 4 | LogError | For errors and exceptions that cannot be handled. These messages indicate a failure in the current operation or request, not an app-wide failure. |
Critical | 5 | LogCritical | For failures that require immediate attention. Examples: data loss scenarios, out of disk space. |
None | 6 | Specifies that no messages should be written. |
In the previous table, the LogLevel is listed from lowest to highest severity.
The Log method's first parameter, LogLevel, indicates the severity of the log. Rather than calling Log(LogLevel, . ) , most developers call the Log extension methods. The Log extension methods call the Log method and specify the LogLevel. For example, the following two logging calls are functionally equivalent and produce the same log:
AppLogEvents.Details is the event ID, and is implicitly represented by a constant Int32 value. AppLogEvents is a class that exposes various named identifier constants and is displayed in the Log event ID section.
The following code creates Information and Warning logs:
In the preceding code, the first Log parameter, AppLogEvents.Read , is the Log event ID. The second parameter is a message template with placeholders for argument values provided by the remaining method parameters. The method parameters are explained in the message template section later in this article.
Configure the appropriate log level and call the correct Log methods to control how much log output is written to a particular storage medium. For example:
- In production:
- Logging at the Trace or Debug levels produces a high-volume of detailed log messages. To control costs and not exceed data storage limits, log Trace and Debug level messages to a high-volume, low-cost data store. Consider limiting Trace and Debug to specific categories.
- Logging at Warning through Critical levels should produce few log messages.
- Costs and storage limits usually aren't a concern.
- Few logs allow more flexibility in data store choices.
- Set to Warning .
- Add Trace or Debug messages when troubleshooting. To limit output, set Trace or Debug only for the categories under investigation.
The following JSON sets Logging:Console:LogLevel:Microsoft:Information :
Log message template formatting
Log message templates support placeholder formatting. Templates are free to specify any valid format for the given type argument. For example, consider the following Information logger message template:
In the preceding example, the DateTimeOffset instance is the type that corresponds to the PlaceHolderName in the logger message template. This name can be anything as the values are ordinal-based. The MMMM dd, yyyy format is valid for the DateTimeOffset type.
For more information on DateTime and DateTimeOffset formatting, see Custom date and time format strings.
Log event ID
Each log can specify an event identifier, the EventId is a structure with an Id and optional Name readonly properties. The sample source code uses the AppLogEvents class to define event IDs:
For more information on converting an int to an EventId , see EventId.Implicit(Int32 to EventId) Operator.
An event ID associates a set of events. For example, all logs related to reading values from a repository might be 1001 .
The logging provider may log the event ID in an ID field, in the logging message, or not at all. The Debug provider doesn't show event IDs. The console provider shows event IDs in brackets after the category:
Some logging providers store the event ID in a field, which allows for filtering on the ID.
Filter function
A filter function is invoked for all providers and categories that don't have rules assigned to them by configuration or code:
The preceding code displays console logs when the category contains Example or Microsoft and the log level is Information or higher.
Log message template
Each log API uses a message template. The message template can contain placeholders for which arguments are provided. Use names for the placeholders, not numbers. The order of placeholders, not their names, determines which parameters are used to provide their values. In the following code, the parameter names are out of sequence in the message template:
The preceding code creates a log message with the parameter values in sequence:
Be mindful when using multiple placeholders within a single message template, as they're ordinal-based. The names are not used to align the arguments to the placeholders.
This approach allows logging providers to implement semantic or structured logging. The arguments themselves are passed to the logging system, not just the formatted message template. This enables logging providers to store the parameter values as fields. Consider the following logger method:
For example, when logging to Azure Table Storage:
- Each Azure Table entity can have ID and RunTime properties.
- Tables with properties simplify queries on logged data. For example, a query can find all logs within a particular RunTime range without having to parse the time out of the text message.
Default log level
If the default log level is not set, the default log level value is Information .
For example, consider the following worker service app:
With the preceding setup, navigating to the privacy or home page produces many Trace , Debug , and Information messages with Microsoft in the category name.
The following code sets the default log level when the default log level is not set in configuration:
Create logs
The following example:
- Creates a logger, ILogger , which uses a log category of the fully qualified name of the type Worker . The log category is a string that is associated with each log.
- Calls LogInformation to log at the Information level. The Log level indicates the severity of the logged event.
Levels and categories are explained in more detail later in this article.
No asynchronous logger methods
Logging should be so fast that it isn't worth the performance cost of asynchronous code. If a logging datastore is slow, don't write to it directly. Consider writing the log messages to a fast store initially, then moving them to the slow store later. For example, when logging to SQL Server, don't do so directly in a Log method, since the Log methods are synchronous. Instead, synchronously add log messages to an in-memory queue and have a background worker pull the messages out of the queue to do the asynchronous work of pushing data to SQL Server.
Log category
When an ILogger object is created, a category is specified. That category is included with each log message created by that instance of ILogger . The category string is arbitrary, but the convention is to use the class name. For example, in an application with a service defined like the following object, the category might be "Example.DefaultService" :
To explicitly specify the category, call LoggerFactory.CreateLogger:
Calling CreateLogger with a fixed name can be useful when used in multiple classes/types so the events can be organized by category.
ILogger is equivalent to calling CreateLogger with the fully qualified type name of T .
Configure logging
In the preceding JSON:
- The "Default" , "Microsoft" , and "Microsoft.Hosting.Lifetime" categories are specified.
- The "Microsoft" category applies to all categories that start with "Microsoft" .
- The "Microsoft" category logs at log level Warning and higher.
- The "Microsoft.Hosting.Lifetime" category is more specific than the "Microsoft" category, so the "Microsoft.Hosting.Lifetime" category logs at log level "Information" and higher.
- A specific log provider is not specified, so LogLevel applies to all the enabled logging providers except for the Windows EventLog.
The Logging property can have LogLevel and log provider properties. The LogLevel specifies the minimum level to log for selected categories. In the preceding JSON, Information and Warning log levels are specified. LogLevel indicates the severity of the log and ranges from 0 to 6:
Trace = 0, Debug = 1, Information = 2, Warning = 3, Error = 4, Critical = 5, and None = 6.
When a LogLevel is specified, logging is enabled for messages at the specified level and higher. In the preceding JSON, the Default category is logged for Information and higher. For example, Information , Warning , Error , and Critical messages are logged. If no LogLevel is specified, logging defaults to the Information level. For more information, see Log levels.
A provider property can specify a LogLevel property. LogLevel under a provider specifies levels to log for that provider, and overrides the non-provider log settings. Consider the following appsettings.json file:
Settings in Logging..LogLevel override settings in Logging.LogLevel . In the preceding JSON, the Debug provider's default log level is set to Information :
The preceding setting specifies the Information log level for every Logging:Debug: category except Microsoft.Hosting . When a specific category is listed, the specific category overrides the default category. In the preceding JSON, the Logging:Debug:LogLevel categories "Microsoft.Hosting" and "Default" override the settings in Logging:LogLevel
The minimum log level can be specified for any of:
- Specific providers: For example, Logging:EventSource:LogLevel:Default:Information
- Specific categories: For example, Logging:LogLevel:Microsoft:Warning
- All providers and all categories: Logging:LogLevel:Default:Warning
Any logs below the minimum level are not:
- Passed to the provider.
- Logged or displayed.
To suppress all logs, specify LogLevel.None. LogLevel.None has a value of 6, which is higher than LogLevel.Critical (5).
If a provider supports log scopes, IncludeScopes indicates whether they're enabled. For more information, see log scopes
The following appsettings.json file contains settings for all of the built-in providers:
In the preceding sample:
Set log level by command line, environment variables, and other configuration
Log level can be set by any of the configuration providers. For example, you can create a persisted environment variable named Logging:LogLevel:Microsoft with a value of Information .
Create and assign persisted environment variable, given the log level value.
In a new instance of the Command Prompt, read the environment variable.
Create and assign persisted environment variable, given the log level value.
In a new instance of the PowerShell, read the environment variable.
Create and assign persisted environment variable, given the log level value.
To read the environment variable.
When configuring environment variables with names that contain . (periods), consider the "Exporting a variable with a dot (.) in it" question on Stack Exchange and its corresponding accepted answer.
After setting an environment variable, restart your integrated development environment (IDE) to ensure that newly added environment variables are available.
- Encrypted at rest and transmitted over an encrypted channel.
- Exposed as environment variables.
NuGet packages
- The interfaces are in Microsoft.Extensions.Logging.Abstractions.
- The default implementations are in Microsoft.Extensions.Logging.
Non-host console app
Logging code for apps without a Generic Host differs in the way providers are added and loggers are created. In a non-host console app, call the provider's Add extension method while creating a LoggerFactory :
The loggerFactory object is used to create an ILogger instance.
How filtering rules are applied
When an ILogger object is created, the ILoggerFactory object selects a single rule per provider to apply to that logger. All messages written by an ILogger instance are filtered based on the selected rules. The most specific rule for each provider and category pair is selected from the available rules.
The following algorithm is used for each provider when an ILogger is created for a given category:
- Select all rules that match the provider or its alias. If no match is found, select all rules with an empty provider.
- From the result of the preceding step, select rules with longest matching category prefix. If no match is found, select all rules that don't specify a category.
- If multiple rules are selected, take the last one.
- If no rules are selected, use LoggingBuilderExtensions.SetMinimumLevel(ILoggingBuilder, LogLevel) to specify the minimum logging level.
Log scopes
A scope can group a set of logical operations. This grouping can be used to attach the same data to each log that's created as part of a set. For example, every log created as part of processing a transaction can include the transaction ID.
- Is an IDisposable type that's returned by the BeginScope method.
- Lasts until it's disposed.
The following providers support scopes:
Use a scope by wrapping logger calls in a using block:
The following JSON enables scopes for the console provider:
The following code enables scopes for the console provider:
Apply log filter rules in code
The preferred approach for setting log filter rules is by using Configuration.
The following example shows how to register filter rules in code:
logging.AddFilter("System", LogLevel.Debug) specifies the System category and log level Debug . The filter is applied to all providers because a specific provider was not configured.
Добрый день. Есть небольшое клиент-серверное приложение на сокетах, работающее с БД. Вопрос: как лучше написать небольшой логгер, позволяющий клиентам и серверу одновременно писать в один текстовый файл (без каши и в историческом порядке) ? Не могу придумать саму концепцию (какой класс, какие поля и методы, параметры доступа). Если бы это было в пределах, допустим, сервера, можно было бы использовать мютекс, а так, как передавать состояние мютекса между объектами ?
Запись логов в файл
Добрый день, подскажите в чём проблема, необходимо сделать след: 1. Логи с приоритетом info -.Запись логов в файл из службы Windows
В классе задаю StreamWriter sw = File.AppendText("Log.txt"); В методе OnStart вызываю .Запись логов в файл с ограниченным числом строк
Всем привет. Как лучше писать логи в файл, который должен содержать не больше 100 тыс. строк? .Запись "логов" в файл
В общем постепенно делаю логирование для программы. Для начала хотел бы разобраться со временем.Не уловил, у вас клиент и сервер на одной локальной машине что ли крутятся?
Если бы это было в пределах, допустим, сервера, можно было бы использовать мютекс, а так, как передавать состояние мютекса между объектами ?
У клиента свой лог, у сервера свой. Они никак не пересекаются и не мешают друг другу.
Накой чорт вы там собрались мучать мьютекс?Более того: накой чорт вам вообще сдался мьютекс для логгера?
Вы что, хотите создать узкое горлышко для потоков?
Что бы многопоточное приложение буквально спотыкалось об этот мьютекс при каждом обращении к логгеру?Каждый поток работает со своим личным контекстом логгера
(грубо говоря на каждый поток - свой логгер, который пишет в свой отдельный файл).При логгировании потоки не ждут друг друга, не стопорятся, не мешают друг другу, и вообще никак не пересекаются.
Сам логгер работает асинхронно. Вызывающая сторона не дожидается окончания записи.
Это позволяет снизить "тормоза" из-за частой записи на жесткий диск.В результате работы, на жестком диске будет несколько лог-файлов. По штуке на каждый поток.
Каждая запись в логе помечается датой/временем.Поэтому все эти файлы можно слить в один, если захочется.
Кроме того, вместо обычного plain-text, можно сливать логи сразу в БД.
Очень удобно потом будет по логам выискивать информацию.Log exceptions
The logger methods have overloads that take an exception parameter:
Exception logging is provider-specific.
Create logs in Main
The following code logs in Main by getting an ILogger instance from DI after building the host:
Читайте также: