Остановка работы кассы при ошибке логирования. Учимся вести логирования с помощью Log4j

Почему так важно запретить самому себе отладку руками?

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

Поэтому вам надо будет несколько раз запускать этот код в отладочном режиме, проводя часы отладки над одним и тем же куском кода. И это только вы один столько времени потратили над этой частью программы. Каждый член команды, кому «посчастливится» работать с этим кодом, будет вынужден прожить ту же самую историю, которую прожили вы.

Я уже не говорю о том, что люди в командах меняются, команды меняются и так далее. Человеко-часы уходят на одно и то же. Перестаньте делать это. Я серьёзно. Возьмите ответственность за других людей на себя. Помогите им не переживать тот же самый участок вашей жизни.

Проблематика: Сложно отлаживать составной код

1. Разбить на отдельные части
2. Выкидываем отладку, просто запрещаем пользоваться режимом Debug
3. Анализируем отдельные части (придумываем для них невалидные ситуации, граничные случаи)
4. Пишем тесты на каждую отдельную часть всего алгоритма
5. В тестах иногда приходится узнавать промежуточные данные, но…
   Отладка нам боле недоступна, поэтому втыкаем Trace в те части, где возникает подозрение на некорректное выполнение алгоритма
6. По трассировке нужно понять причину проблемы
7. Если не понятно, то чаще всего либо стоит написать ещё тест, либо выполнить трассировку на один этап раньше

Таким образом, вы избавляете других людей от отладки этого кода, т.к. если возникнет проблема, то человек посмотрит ваши логи и поймёт в чём причина. Логировать стоит только важные участки алгоритма.

Давайте посмотрим пример. Вы знаете, что по отдельности все реализации интерфейсов работают (т.к. написаны тесты, доказывающие это). Но при взаимодействии всего вместе возникает некорректное поведение. Что вам нужно? Нужно логировать ответы от «корректных» интерфейсов:

Void Register(User user) { // на этом участке не нужно ничего логировать, // т.к. всё будет понятно из исключения var isExists = _userRepository.IsUserExists(user); if (isExists) { throw new InvalidOperationException($"User already exists: {user}"); } // а вот это уже можно и залогировать, // т.к. от этого зависят дальнейшие детали алгоритма var roleInOtherService = _removeService.GetRole(user); _log.Trace($"Remote role: {roleInOtherService}") switch (roleInOtherService) { case "...": break; ... } // тут нам не критично, если пользователю не добавили // определённые привелегии в каком-то удалённом сервисе, // но мы бы хотели знать об этом foreach (var privilege in Privileges) { var isSuccess = _privilegeRemoteService.Grant(user, privilege); if (isSuccess) { _log.Trace($"Add privilege: {privilege} to User: {user}"); } else { _log.Trace($"Privilege: {privilege} not added to User: {user}"); } } ... }
В этом примере видно, как мы трассируем отдельные части алгоритма для того, чтобы можно было зафиксировать тот или иной этап его выполнения. Посмотрев на логи, станет ясно в чём причина. В реальной жизни весь этот алгоритм стоило бы разбить на отдельные методы, но суть от этого не меняется.

Всё это в разы ускоряет написание кода. Вам не нужно бежать по циклу с F10 для того, чтобы понять на какой итерации цикла возникла проблема. Просто залогируйте состояние нужных вам объектов при определённых условиях на определённой итерации цикла.

В конечном итоге вы оставляете важные логи и удаляете побочные логи, например, где вы узнавали состояние объекта на определённой итерации цикла. Такие логи не помогут вашим коллегам, т.к. вы, скорее всего, уже поняли проблему некорректного алгоритма и исправили её. Если нет, то ведите разработку в вашей ветке до тех пор, пока не найдёте в чём причина и не исправите проблему. А вот логи, которые записывают важные результаты от выполнения других алгоритмов, понадобятся всем. Поэтому их стоит оставить.

Что если нам не нужен этот мусор? В таком случае выполняйте трассировку только в рамках отладки, а затем подчищайте за собой.

В данном разделе представлены рекомендации по работе с программами для сбора логов. Данная информация необходима службе технической поддержки для точной диагностики проблемы на рабочем месте пользователя. Ниже доступны инструкции для приложений.

Сбор логов https с помощью FiddlerCap

Установка FiddlerCap

Необходимо скачать и запустить приложение .

В открывшемся окне нажать на кнопку «Install». В строке Destination Folder будет указан путь до папки, в которую установится FiddlerCap. По умолчанию там указывается Рабочий стол.

Дождаться окончания установки и нажать кнопку «Close».

Сбор логов с помощью FiddlerCap

Найти папку FiddlerCap в той директории, которая была выбрана на этапе установки. По умолчанию FiddlerCap устанавливается на Рабочий стол. В папке FiddlerCap запустить файл «FiddlerCap.exe».

В пункте «Настройки захвата» установить три галки:

• сохранять двоичные данные,
• расшифровать HTTPS трафик,
• хранить куки и POST формы.

Если появится предупреждение об установке сертификата, то в нем следует нажать кнопку «Да». При необходимости, сертификат будет предложено удалить при сохранении логов.

Закрыть все браузеры, открытые на компьютере. Нажать на кнопку «Начать захват». Открыть программу, при работе с которой появляется ошибка (например, Контур.Экстерн), и воспроизвести ошибку.

После того, как ошибка будет воспроизведена, необходимо нажать на кнопку «Остановить захват» в окне программы FiddlerCap. Логирование завершится.

Выбрать папку для сохранения.

Файл с логами будет сохранен в выбранной папке.

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

Запись сетевого трафика в Internet Explorer

Для записи сетевого трафика в Internet Explorer необходимо открыть необходимую страницу в Internet Explorer. В Internet Explorer перейти в меню «Сервис» > «Средства разработчика F12» ("Tools" > «Developer Tools F12") F12 .

Если меню «Сервис» не отображается, то нажать клавишу «Alt» на клавиатуре .

Перейти на вкладку «Сеть (Network)» > «Ctrl+4». Включить сбор сетевого трафика: в Internet Explorer 9 нажать «Начать сбор». В Internet Explorer 11 нажать на кнопку с зеленым треугольником.

Воспроизвести ошибку (например, обновить страницу, либо перейти по нужной ссылке). Сохранить собранный лог, нажав на изображение дискеты.

В ыбрать папку для сохранения, ввести имя файла, нажа ть «Сохранить». Файл будет создан в xml формате. Создание лога завершено.

Запись сетевого трафика в Mozilla Firefox

Для записи сетевого трафика в Mozilla Firefox необходимо открыть необходимую страницу в Mozilla Firefox. В IMozilla Firefox перейти в меню «Сервис» > «Разработка» > «Средства разработчика (Ctrl + Shift + I) либо нажать на клавиатуре клавишу F12 .

Перейти на вкладку «Сеть» и обновите страницу, нажав на клавиатуре клавишу F5 . Воспроизведите ошибку.

Выделите любую запись из лога — нажмите по нему правой кнопкой мыши и нажмите на «Сохранить все как HAR».

Запись сетевого трафика в Google Chrome

Для записи сетевого трафика в Google Chrome необходимо открыть необходимую страницу в Google Chrome. В Google Chrome перейти в меню «Сервис» > «Дополнительные инструменты» >«Средства разработчика (Ctrl +Shift +I) либо нажать на клавиатуре клавишу F12 .

Передите в раздел Network и обновите страницу, нажав на клавиатуре клавишу F5 . Воспроизведите ошибку.

Если запись логов не началась автоматически, нажмите на кнопку «Record Network Log».

Выделите любую запись из лога, нажмите по нему правой кнопкой мыши и нажмите на «Save as HAR with content».

Выберите папку для сохранения, введите имя файла, нажмите на сохранить. Файл будет сохранен в формате har.

Установка

Необходимо скач ать и запустить приложение . На предложение начать установку следует ответить утвердительно, нажав на кнопку «Да».

В открывшемся окне нажать на кнопку «Next».

В следующем окне необходимо установить переключатель «I accept the terms in the Licence Agreement» и кликнуть по кнопке «Next».

Выбрать тип установки «Typical».

Отметить пункт «Create shortcut for Microsoft Network Monitor on the desktop» (Создать ярлык на рабочем столе) и нажать на кнопку «Install».

Нажать на кнопку «Finish» для завершения установки.

После окончания установки необходимо дождаться окончания автоматической настройки компонента Microsoft Network Monitior 3.3 Parsers.

Запуск логирования

Закрыть неиспользуемое программное обеспечение (это необходимо для исключения сохранения в лог активности сторонних продуктов). Запустить программу с помощью ярлыка на рабочем столе.

В главном окне программы выбрать меню «File» > «New» > «Capture».

Нажать на кнопку «Start», после чего свернуть программу и воспроизвести ошибку.

Воспроизвессти ошибку, нажать на кнопку «Stop», выбрать меню «File» > «Save As», указать каталог для сохранения и имя файла и нажать на кнопку «Сохранить». Создание лога завершено.

Process Monitor

Чтобы начать логирование при помощи программы Process Monitor, необходимо выполнить следующие шаги:

Закрыть неиспользуемое программное обеспечение (это необходимо для исключения сохранения в лог активности сторонних продуктов), скач ать и запустить приложение .

После запуска программы выбрать меню «File» > «Capture Events». Логирование будет остановлено. Выбрать меню «Edit» > «Clear Display». Автоматически записанный лог будет удален. Программа готова к работе.

Выбрать меню «File» > «Capture Events». Логирование будет запущено. Свернуть приложение и воспроизвести ошибку.

Восстановить приложение и выбрать меню «File» > «Capture Events». Логирование будет остановлено. Выбрать меню «File» > «Save». Установить переключатель «All Events».

Кликнуть по кнопке с тремя точками справа от поля «Path», указать папку для сохранения и имя файла (рекомендуется оставить по умолчанию) и нажать на кнопку «Сохранить».

В окне параметров сохранения файла нажать на кнопку «Сохранить». Создание лога завершено.

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

Шаг 0. Обзор

Логирование – не используя термины википедии, то это возможность следить за процесом выполнения бизнес-логики проекта.

Зачем нужно логирование и что оно даёт?

Допустим у вас есть WEB-проект, и он что-то делает, сейчас не важно что именно. Допустим это интернет магазин, на котором при оформлении заказа нужно отправить на почту покупателю отчет о его покупке, но почтовый сервер вышел из строя, и программно письмо не отправилось.

Вы, как человек который администрирует магазин начнет разбераться в чем же проблема. Неопытный человек будет долго искать проблему, а опытный сразу полезет в логи сервера, но там все логи сервера и найти то что нужно вам сложно.

В этом случае решение следующее, выводить нужные вам логи в отдельный файл. Но как понять, какие из всех логов, которые сыпятся в общий лог сервера нужны вам? Для этого нужно реализовать свою систему логирования, где вы сможите указать какие логи куда выводить, или же настроить уровни логирования.

В данном уроке мы рассмотрим как сконфигурировать и начать использовать Log4j.

Шаг 1. Создаем проект и добавляем завимости

Запускаем всеми любимую Intellij IDEA и тыкаем New Project выбираем Maven Module и называем его:

Теперь в pom.xml жлбавим зависимость:

log4j log4j 1.2.17

Это все зависимости, которые надо было подключить.

Шаг 2. Создание примитивной логики для примера

Давайте создадим класс в котором была бы бизнес-логика, назовем его OrderLogic :

Package com.devcolibri.logpack; public class OrderLogic { public void doOrder(){ // какае-то логика System.out.println("Заказ оформлен!"); addToCart(); } private void addToCart() { // добавление товара в корзину System.out.println("Товар добавлен в корзину"); } }

Хочу обратить ваше внимание на то, что логика данного проекта не важна, так как мы рассматриваем логирование, для этого я и подготовил примитивную логику класса OrderLogic.

И теперь создаем Main класс:

Package com.devcolibri.logpack; public class Main { private static OrderLogic logic; public static void main(String args) { logic = new OrderLogic(); logic.doOrder(); } }

В результате выполнения данного кода, мы получим следующее:

Заказ оформлен! Товар добавлен в корзину

Как видите пока ничего нового.

Шаг 3. Конфигурируем Log4j

Чтобы гибко управлять логированием стоит создать в resources/ файл log4j .properties:

Теперь в этот файл добавим пару строк конфигураций:

# Уровень логирования log4j.rootLogger=INFO, file # Апендер для работы с файлами log4j.appender.file=org.apache.log4j.RollingFileAppender # Путь где будет создаваться лог файл log4j.appender.file.File=C:\\TMP\\log_file.log # Указываем максимальный размер файла с логами log4j.appender.file.MaxFileSize=1MB # Конфигурируем шаблон вывода логов в файл log4j.appender.file.layout=org.apache.log4j.PatternLayout log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n

Теперь давайте более детальней разберем строку формирования шаблона:

Log4j.appender.file.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n

Значения:

%d{yyyy-MM-dd HH:mm:ss} – выводит дату в формате 2014-01-14 23:55:57

%-5p – выводит уровень лога (ERROR , DEBUG , INFO …), цифра 5 означает что всегда использовать 5 символов остальное дополнится пробелами, а минус (-), то что позиционирование по левой стороне.

%L – номер строки в которой произошёл вызов записи в лог.

%m – сообщение, которое передали в лог.

%n – переход на новую строку.

Шаг 4. Добавляем примитивное логирование

Теперь в класс OrderLogic добави логирование и посмотрим на результат:

Package com.devcolibri.logpack; import org.apache.log4j.Logger; public class OrderLogic { // Инициализация логера private static final Logger log = Logger.getLogger(OrderLogic.class); public void doOrder(){ // какае-то логика System.out.println("Заказ оформлен!"); // логируем инфо log.info("Это информационное сообщение!"); addToCart(); } private void addToCart() { // добавление товара в корзину System.out.println("Товар добавлен в корзину"); // логируем ошибку log.error("Это сообщение ошибки"); } }

Теперь давайте запустим код опять. Мы получим тот же результат, вот только уже по пути C://TMP/ будет лежать файл log_file.log со следующим содержимым:

2014-01-14 23:55:57 INFO OrderLogic:12 - Это информационное сообщение! 2014-01-14 23:55:57 ERROR OrderLogic:19 - Это сообщение ошибки

Когда работаешь удалённо сложно оценивать время своей работы. У ребят в офисе с этим проблем никаких нет. Они пришли в девять, ушли в пять. Значит восемь часов поработали. А когда ты сидишь дома или ходишь по кафе и коворкингам, относишься к этому по-другому, и потому легко попасть в огромную яму переработок из-за неправильного логирования.

Раньше я рассуждал просто. Моя работа заключается в том, чтобы писать код. Значит, когда я пишу код, я работаю. Получается, что мне нужно логировать время написания кода. После месяца таких логирований возникал вопрос: почему по цифрам получается, что вместо 40 часов в неделю я работал 25-30?

Первый же вывод, к которому легче всего прийти, - я весь месяц работал меньше положенного. Значит следующий месяц надо работать более активно! Но после месяца такой «активной» работы получалось, что работа-то сделана, а с самочувствием что-то явно не так. А ещё все лампочки горят красным , и работа как-то всё медленнее и медленнее работается.

Читателю со стороны, конечно, очевидно, что дело в неправильном логировании. Но если подходить к работе ответственно, самостоятельно в это сложно поверить. Ведь ты по-честному логируешь время, которое потратил на задачу, и по ощущениям ты не можешь потратить на неё больше. «Но у других ведь получается?»

За ответом можно сходить в храм под названием «Наука». Вот что рассказывает Барбара Окли в первом же видео курса Learning How to Learn (в недавней годноте была ссылка на конспект курса):

Что вы делаете, когда не получается до чего-то «додуматься»? Для зомби всё просто: они просто продолжают биться головой о стену. Но живой мозг куда сложнее. Однако, если вы поймёте хотя бы основы того, как он работает, то сможете учиться с большей лёгкостью и с меньшим разочарованием.

Исследователи выяснили, что у нас есть два абсолютно разных «режима мышления». Назовём их сфокусированный и расслабленный.

Все знакомы со сфокусированным режимом. Это когда мы концентрируемся на чём-то, что пытаемся выучить или понять. Но мало кто знает, в чём суть расслабленного режима.

Используем аналогию с пинболом, чтобы разобраться.

Если вы помните, пинбол работает так: вы оттягиваете поршень, затем отпускаете его, он бьёт по шарику, и тот движется внутри автомата, сталкиваясь с резиновыми препятствиями и тем самым накапливая вам очки. Это похоже на то, как работает мозг. В сфокусированном режиме резиновые препятствия стоят очень близко друг к другу, и шарик может двигаться по одной и той же «тропинке», безрезультатно пытаясь вырваться за пределы. А за пределами этих препятствий (может даже совсем в другом углу «автомата») вполне может быть «правильная тропинка», которая приведёт вас к решению текущей задачи. И что же делать в таком случае?

Чтобы добраться до этой «правильной тропинки» вам нужен иной способ мышления - расслабленный. В нём препятствия стоят на большем расстоянии друг от друга, и потому шарик может спокойно двигаться от одного к другому, затрагивая максимально возможное количество оных, и таким образом создавая новые нейронные связи, которых так не хватало в сфокусированном режиме.

Важно понимать, что вы не можете находиться в обоих режимах сразу. Это как монета, которая может быть повёрнута к вам только одной стороной: или сфокусированной, или расслабленной.

Это был мой вольный перевод-пересказ первой лекции , которая доступна без подписки на курс. Лучше посмотрите оригинал, если понимаете английский.

Вернёмся к проблеме. Скорее всего вы тоже часто замечали за собой, что решения творческих задач часто приходят в тот момент, когда вы максимально расслаблены: лежите в ванной, стоите у окна с кружкой чая, сидите в кресле с котом, гуляете вечером на улице. Я обожаю эти моменты, и всегда удивляюсь тому, насколько мозг круто работает. Но это какие-то особенно пиковые состояния, во время которых приходят самые светлые и гениальные идеи. На деле же есть ещё сотни микро-состояний расслабленности, когда вы просто отвлекаетесь от текущей проблемы и идёте заваривать чай, нарезать бутерброды, открывать окно, заказывать очередной кофе у бариста. Или когда просто пару минут залипаете куда-то в стену, потому что внезапно отвели глаза от экрана и «потерялись».

Получается, что учитывая время работы, стоит не забывать и о времени отдыха, потому что это и есть то самое расслабленное состояние, в котором рождаются новые идеи. Если вернуться назад и вспомнить о ребятах из офиса, то они редко сидят на месте по паре часов (как это часто бывает, когда вокруг никого), а постоянно куда-то ходят, с кем-то общаются, обсуждают не относящиеся к работе темы и так далее.

Если вы не забываете о том, что работа - это не только активная часть, но и пассивная (отдых), то скорее всего вам не понадобится часто перезагружаться , и в следующий раз при оценке задач вы не будете думать, что если у вас есть 8 рабочих часов, то это время для непрерывной работы, в которой нет места отдыху.

Нужно логировать всё, что помогает решить задачу. В том числе и отдых.