Когда вы отлаживаете программу, то вы, сами того не осознавая, думаете что за один отладочный сеанс исправите все проблемы, возникшие в рамках этой задачи. Но наша недальновидность не хочет верить в то, что на самом деле там не одна проблема, а несколько. И за один отладочный сеанс не получится решить все эти проблемы.
Поэтому вам надо будет несколько раз запускать этот код в отладочном режиме, проводя часы отладки над одним и тем же куском кода. И это только вы один столько времени потратили над этой частью программы. Каждый член команды, кому «посчастливится» работать с этим кодом, будет вынужден прожить ту же самую историю, которую прожили вы.
Я уже не говорю о том, что люди в командах меняются, команды меняются и так далее. Человеко-часы уходят на одно и то же. Перестаньте делать это. Я серьёзно. Возьмите ответственность за других людей на себя. Помогите им не переживать тот же самый участок вашей жизни.
Проблематика: Сложно отлаживать составной код
Возможный алгоритм решения проблемы:
- Разбить на отдельные части
- Выкидываем отладку, просто запрещаем пользоваться режимом Debug
- Анализируем отдельные части (придумываем для них невалидные ситуации, граничные случаи)
- Пишем тесты на каждую отдельную часть всего алгоритма
- В тестах иногда приходится узнавать промежуточные данные, но…
Отладка нам боле недоступна, поэтому втыкаем Trace в те части, где возникает подозрение на некорректное выполнение алгоритма - По трассировке нужно понять причину проблемы
- Если не понятно, то чаще всего либо стоит написать ещё тест, либо выполнить трассировку на один этап раньше
Решением является автоматизированное тестирование с использованием логирования. Вы пишите тесты на все (или почти все) ситуации, которые приводят к проблемам. Плюс, если возникает потребность в отладке, то вы трассируете до тех пор, пока не разберётесь в проблеме.
Таким образом, вы избавляете других людей от отладки этого кода, т.к. если возникнет проблема, то человек посмотрит ваши логи и поймёт в чём причина. Логировать стоит только важные участки алгоритма.
Давайте посмотрим пример. Вы знаете, что по отдельности все реализации интерфейсов работают (т.к. написаны тесты, доказывающие это). Но при взаимодействии всего вместе возникает некорректное поведение. Что вам нужно? Нужно логировать ответы от «корректных» интерфейсов:
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 для того, чтобы понять на какой итерации цикла возникла проблема. Просто залогируйте состояние нужных вам объектов при определённых условиях на определённой итерации цикла.
В конечном итоге вы оставляете важные логи и удаляете побочные логи, например, где вы узнавали состояние объекта на определённой итерации цикла. Такие логи не помогут вашим коллегам, т.к. вы, скорее всего, уже поняли проблему некорректного алгоритма и исправили её. Если нет, то ведите разработку в вашей ветке до тех пор, пока не найдёте в чём причина и не исправите проблему. А вот логи, которые записывают важные результаты от выполнения других алгоритмов, понадобятся всем. Поэтому их стоит оставить.
Что если нам не нужен этот мусор? В таком случае выполняйте трассировку только в рамках отладки, а затем подчищайте за собой.
| Плюсы | Минусы |
|---|---|
| Есть возможность проследить выполнение алгоритма без отладки | Приходится писать код трассировки |
| В production логи будут собирать иногда нужные данные | В production логи будут собирать иногда ненужные данные |
| Время на отладку сокращается, т.к. вы часто запускаете код и тут же видите результаты его выполнения (всё как на ладони) | Нужно подчищать за собой. Это иногда приводит к повторному написанию кода трассировки |
| Коллеги могут прослеживать выполнение алгоритма по логам | Коллегам приходится смотреть не только на сам алгоритм, но и на трассировку его выполнения |
| Логирование — единственный способ отладки недетерминированных сценариев (например, многопоточность или сеть) | В production уменьшается производительность из-за операций I/O и CPU |
Напоследок хотелось бы сказать вот что: думайте своей головой. Не нужно прыгать из крайности в крайность. Порой отладка руками действительно быстрее решит проблему здесь и сейчас. Но как только вы заметили, что что-то быстро, здесь и сейчас не получается, пора переключиться на другой режим.
Комментарии (62)
VolCh
06.05.2018 15:10+5Почему-то нет в минусах уменьшения производительности на продакшене. Запись ненужных данных это не только место на диске, но и время CPU, и время iowait.
MacIn
06.05.2018 20:05Это лечится логированием по флагу, которым можно как-то управлять извне. Возникла странная ситуация — перекинул флаг, посмотрел логи.
VolCh
06.05.2018 21:07Это уже мало отличается от изменения исходников.
MacIn
07.05.2018 01:00Простите, не понял. Каким именно образом «мало отличается от изменения исходников»?
VolCh
07.05.2018 07:38Ну какой-то флаг устанавливать в, например, environment переменных процессов и рестартовать их.
saterenko
07.05.2018 10:05В конфиге демона меняется «log.level»:«error» на «log.level»:«debug» и процессу шлётся kill -s HUP, демон загружает новый конфиг, запускает с ним новые процессы, если они запустились без проблем, останавливает старые… Ни чего не перезагружается, ни какие соединения не теряются…
VolCh
07.05.2018 15:00А есть конфиг и демон?
saterenko
07.05.2018 15:08Есть, но дать не смогу, не имею права. Сделано по аналогии с nginx, можете там посмотреть…
VolCh
08.05.2018 06:19Я к тому, что вы исходите из того, что есть демон и есть конфиг у него. То есть для каких-то задач приложение уже демонизировано, управляется сигналами и конфигурируется через конфиги. Сейчас в тренде другие варианты: приложение не демонизируется (в том числе nginx), конфигурируется через env (для nginx — динамическая генерация файловых конфигов из них), из сигналов максимум SIGTERM обрабатывает для graceful shutdown
saterenko
08.05.2018 08:21У вас есть пруфы на этот тренд? То, что демон, в том числе и nginx можно запустить без демонизации — это понятно, демонизацию на себя возмёт какой-нибудь systemd. Генерация из конфигов переменных env для последующего их использования в демоне — это какое-то особое извращение, видимо следствие хайпа по докерам и т.п.
Объясните, пожалуйста, как вы с помощью одного SIGTERM перезапустите процесс без сброса открытых соединений?VolCh
08.05.2018 10:16Например 12factor.net/ru
И, да, сильно с докером коррелирует. Явной причинно-следственной связи нет, но докер чаще всего используется в реализациях подхода. И этот подход не предполагает перезапуска процесса на той же физической или виртуальной машине. Может даже в другом датацентре она запустится в среде не предполагающей перкидывание соединений с хоста на хост.saterenko
08.05.2018 10:53По ссылке документация по реализации некоторой концепции коих в разработке тысячи, если не миллионы. Наличие этого документа говорит не о тренде, а о наличии концепции.
Но мы уже ушли от темы. Я вам ответил как я в своей среде реализую включение вывода в лог нужной информации, без перезапуска демона. Вы работаете в другой среде, у вас другой механизм.VolCh
08.05.2018 14:29Не в среде дело, а в самом приложении обычно. Реализовывать демонизацию, чтение конфигов и перечитывание их после SIGHUP только для того, чтобы уровень отладки изменить… Ну, может быть когда-то имеет смысл.
imanushin
06.05.2018 21:31+1Почему-то нет в минусах уменьшения производительности на продакшене.
Грамотно сделанные логи практически не влияют на производительность. Для Java — см. log4j2 в асинхронном режиме. Для .Net — NLog (тоже в асинхронном режиме). Что важно — часть используют для той же Java slf4/log4 (не log4j2, это важно), которые просто не умеют в асинхронность. А значит каждый вызов log.info приведет к записи на диск.
Более того, если мы делаем Web сервис, то легко можно организовать систему, когда логи копятся в памяти, пока работает request. И сбрасываются на диск после него. Тут одновременно и буфферизация и асинхронность. Однако важно — это для .Net/Java, по остальным платформам не подскажу.
vedenin1980
06.05.2018 23:03Грамотно сделанные логи практически не влияют на производительность.
В некоторых случаях влияют, если их ставить не подумав. У меня как попало логирование в цикл где перебирались миллиарды и триллионы записей (данные были очень близки к BigData, но все-таки за ночь успевали обработаться на одном сервере), деградация производительности оказалось раза в 3, просто никакая асинхроность не поместит такую массу данных в памяти (мы данные специально брали в архиве, на лету разархивировали, обрабатывали и снова архивировали — это давала значительные прирост в скорости за счет записи и чтения на диск, а логи, естественно, писались без архивирования).
В общем, при реально высокопроизводительном приложении ( не при обычных web servic'ах) — нужно быть очень внимательным с логированием, оно, кстати, и место на диске забивает влет, если не подумать.saterenko
07.05.2018 10:09В высокопроизводительных приложениях в принципе нужно быть очень внимательными, можно же не только логированием убить производительность… А вот возможность включить вывод отладочной информации в лог на работающем демоне меня не раз спасала. Это очень редко требовалось, но очень ускоряло поиск и решение проблемы.
aleksandy
07.05.2018 07:06используют для той же Java slf4/log4 (не log4j2, это важно), которые просто не умеют в асинхронность.
Насчёт log4j согласен, но чего ради slf4j обвиняется в неумении?
slf4f — это просто фасад, набор интерфейсов, за которыми может скрываться какая угодно их имплементация. Например, авторский logback умеет быть асинхронным.
DistortNeo
06.05.2018 16:11+5Ещё стоит отметить, что логирование — чуть ли не единственный способ отладки недетерминированных сценариев, например, многопоточность, работа с сетью.
michael_vostrikov
06.05.2018 18:47-3Если ошибка воспроизводится, то достаточно брейкпойнт поставить.
AstarothAst
06.05.2018 20:08+1И что вы в этом случае увидите? Предположим вы увидели мусор в данных — вам интересен не сам факт того, что на входе мусор, а почему он там возник. А возник он там из-за того, что соседний поток данные попортил. Если он это записал в лог, то последовательность событий вы худо-бедно восстановите, а вот если у вас только бряк, то увы…
michael_vostrikov
06.05.2018 21:26-3Ну ставим бряк в соседнем потоке на код, изменяющий данные, в Watch\Evaluate смотрим данные. Не вижу принципиальных отличий от логирования. Вот в логах как раз будет мусор, но непонятно почему он там возник, а в отладке можно по шагам проверить, как данные изменяются.
DistortNeo
06.05.2018 21:33+1В том-то и дело, что в случае многопоточного приложения вы не можете отлаживать по шагам.
michael_vostrikov
07.05.2018 06:00Можете описать какой-то конкретный кейс?
Не раз делал отладку в приложениях с несколькими потоками, например при взломе денег/здоровья/оружия в играх. Расставляем брекпойнты, в пределах одной-двух функций шагаем по F10, потом запускаем по F9 до следующего брекпойнта. Хардварные брекпойнты на запись тоже полезная штука.saterenko
07.05.2018 10:14Не всегда получается локально в песочнице решить проблему. Например, демон, который обрабатывает тесячи запросов в секунду и иногда, раз в час, почему-то падает… Т.е. это примерно один запрос на 10 миллионов создал проблему… Логи позволяют найти этот запрос и повторить у себя в песочнице, не останавливая при этом работу прода.
michael_vostrikov
07.05.2018 10:24+2Я с этим и не спорю, я же написал «Если ошибка воспроизводится». Плавающие баги конечно лучше логами искать.
DistortNeo
07.05.2018 13:27Можете описать какой-то конкретный кейс?
Например, попытка понять, почему при обработке изображения в 1 поток всё хорошо, а в при использовании parallel_for на изображении иногда появляется мусор. Точнее, почему — ответ очевидный (второй поток начал использовать ещё не вычисленные значения), а нужно понять, что сделать, чтобы этого избежать, не потеряв при этом в производительности.
Или другой пример: отладка протокола общения с какой-нибудь железкой, которая шлёт пинг-пакеты, на которые клиент должен сразу же отвечать. Если начать отлаживать по шагам, то возникнут большие задержки, и железка решит, что вы отвалились по таймауту.
Расставляем брекпойнты, в пределах одной-двух функций шагаем по F10, потом запускаем по F9 до следующего брекпойнта.
Дело в том, что пока вы шагаете по функции, остальные потоки тоже работают.
И если вы работаете с общими данными, то возможно всякое.
AstarothAst
07.05.2018 16:09Простите, но вы прям уверены, что можете «поставить бряк в соседнем потоке»? А как вы этот поток найдете? Как узнаете какое из множества мест, в которых мутируют данные вам нужно? Это не говоря уже про то, что к моменту ошибки данные УЖЕ изменены, и бряк ставить просто некуда, вы это место уже покинули.
michael_vostrikov
07.05.2018 17:06А как вы этот поток найдете?
Примерно вот так:
Как узнаете какое из множества мест, в которых мутируют данные вам нужно?
А как вы узнаете, в какое из множества мест логирование добавить? Если точное место возникновения ошибки неизвестно, можно поставить на все места. Туда же, куда мы бы добавили логирование.
Но вообще я говорил о случае, когда ошибка стабильно воспроизводится. То есть можно сказать, что в этом месте ошибки еще нет, а в этом уже есть. Ставим несколько точек в разных местах, между ними запускаем, чтобы работали все потоки. Если есть возможность поставить брекпойнт на изменение данных, то еще лучше, остановится сразу в нужном потоке.
к моменту ошибки данные УЖЕ изменены, и бряк ставить просто некуда
Извините, эту часть я не понял. Код никуда не девается, ставить надо заранее.
AstarothAst
08.05.2018 10:55Примерно вот так
Сдается мне этот способ настолько трудозатратен, что всерьез его рассматривать банально не стоит :)
А как вы узнаете, в какое из множества мест логирование добавить?
В том и дело, что логгирование добавляется при написании кода, а не после возникновения ошибки. То есть я не буду узнавать «в какое из множества мест добавить лог» — я его просто добавлю во множество мест, и получу вполне ясную, хоть и весьма объемную картину происходящего.
Но вообще я говорил о случае, когда ошибка стабильно воспроизводится. То есть можно сказать, что в этом месте ошибки еще нет, а в этом уже есть. Ставим несколько точек в разных местах, между ними запускаем, чтобы работали все потоки. Если есть возможность поставить брекпойнт на изменение данных, то еще лучше, остановится сразу в нужном потоке.
Не поможет в случае, когда данные сломаны в момент T, а в виде ошибки проявляются в момент T+сколько-то итераций. Придется идти вверх по коду, в поисках места, где данные были поломаны, а таких мест может быть много. Стабильность воспроизведения ошибки тут мало что дает.
Извините, эту часть я не понял. Код никуда не девается, ставить надо заранее.
Так куда заранее? Данные пришли, скажем по сети, в виде websocket-сообщения, были преобразованы, разложены в разные структуры данных, которые прошли многопоточный конвеер обработки и преобразования, протиснулись сквозь разные очереди и преобразователи, и на выходе вы обнаруживаете, что там, где ожидается не ноль — у вас ноль. При чем не всегда, а в одном случае на миллион входных сообщений. Имея лог вы возьмете id поломанного сообщения, и сможете отследить весь процесс преобразования в обратную сторону, и найдете место, где возник этот ноль. В этом месте может быть даже ошибки не будет — ошибка будет еще раньше. И вы продолжите идти по логу вверх… Как в таком виде будет выглядеть разбор бряками? Поставил бряк с условием «если ноль», запустился, дождался останова, пошел смотреть, что на входе в метод, пошел выше, поставил бряк с условием… смыть, повторить. Или не так?michael_vostrikov
08.05.2018 13:11Сдается мне этот способ настолько трудозатратен, что всерьез его рассматривать банально не стоит
Я там специально активировал окно со списком потоков. Что там трудозатратно? Посмотреть список, переключиться двойным кликом? В Visual Studio такое же окно есть, в других отладчиках думаю тоже.
То есть я не буду узнавать «в какое из множества мест добавить лог» — я его просто добавлю во множество мест, и получу вполне ясную, хоть и весьма объемную картину происходящего.
С брекпойнтами абсолютно аналогично. Ставим везде где надо, проверяем значения переменных.
Не поможет в случае, когда данные сломаны в момент T, а в виде ошибки проявляются в момент T+сколько-то итераций. Придется идти вверх по коду, в поисках места, где данные были поломаны, а таких мест может быть много. Стабильность воспроизведения ошибки тут мало что дает.
То, что вы описали, это и есть стандартная работа с отладчиком. Он можно сказать и предназначен, чтобы делать такие вещи проще. Стабильность воспроизведения наоборот важна, она дает возможность перезапустить выполненение, поставив точки в другие места, если вдруг пропустил момент появления ошибки.
И первая точка ставится на момент (T минус сколько-то итераций). Он прикидывается исходя из логики. Если не угадали, ставим еще раньше, перезапускаем. И нет, на это уходит меньше времени, чем читать кучу логов.
При чем не всегда, а в одном случае на миллион входных сообщений.
Вот именно поэтому стабильность воспроизведения важна. Важно знать, что вот это сообщение или группа сообщений дают ошибку.
Имея лог вы возьмете id поломанного сообщения, и сможете отследить весь процесс преобразования в обратную сторону, и найдете место, где возник этот ноль.
И точно так же можно взять id поломанного сообщения, отследить логику его обработки в отладчике, и найти место, где возникает этот ноль.
Как в таком виде будет выглядеть разбор бряками?
Ставим бряк в процедуру приема сообщения, в процедуру возврата результата, в процедуры, которые работают с этим полем структуры данных.
Запускаем, отправляем сообщение, которое обрабатывается неправильно, останавливается на приеме сообщения. Смотрим, на входе пришло 100.
Запускаем выполнение дальше, останавливается на процедуре разложения в структуры. Проверяем, раскладывается правильно.
Запускаем, останавливается на выходе из конвейера. Проверяем, обработано правильно.
Запускаем, останавливается на выходе из преобразователя. Проверяем, вот он ноль появился.
Проверяем код преобразователя. Ага, в коде написано$x -= $x;вместо$x -= $y;.
Или если не нашли, расставляем бряки в преобразователе, перезапускаем, повторяем.
При этом можно смотреть не только то, что залогировано, а вообще весь контекст — переменные, конфиги, родительские объекты, где-то даже методы вызывать.
И это если код не менять. А если менять, то можно раскидать по коду проверкиif ($obj->field == 0) { ... }и поставить бряки в тело условия. Тогда сразу можно найти, где появляется ноль. Похоже на логирование, только логгер в зависимости пробрасывать не надо, логировать все не надо, тестировать этот код не надо, и на продакшн он не влияет, потому что коммитить его не надо.
TimsTims
06.05.2018 18:44+3Всё бы ничего, но:
Анализируем отдельные части (придумываем для них невалидные ситуации, граничные случаи)
Бывают случаи, когда ты уже не можешь представить, что могло пойти не так, у тебя кончилась вся фантазия, ты знаешь что результат не верный, но не можешь найти причину. Вариант "придумывать" уже не катит, нужно ставить дебаги, следить за потоками данных.
HomunCulus
06.05.2018 20:04+1Да, сняли с языка.
Но все же не выкидываем Дебаг. И то и то полезно.
Но в целом, именно хорошее логгирование позволит понять почему именно в проде через неделю-две что то падает. Мультипоточность, утечки памяти, и прочие вещи связанные с CAP теоремой ловятся часто только через логи. НО. Часто возникают ситуации, когда надо идти и смотреть в ключевых точках что происходит, и от этого никуда не деться.
Мир не черно белый. Нет одного правильного подхода. Серединный путь, как говорил еще Будда про ИТ разработку.
MonkAlex
06.05.2018 20:45Кейс с реальных продуктивных багов. У меня создается сущность с 20+ свойств.
И все свойства меняются, порядка 200 изменений(связных) за пару минут в рамках одной бизнес-операции. И в редких редких случаях одно-два свойства оказываются не в том состоянии.
Ещё раз, изменение свойств — связное. Т.е. при изменении свойства А может быть изменено свойство Б и иногда В. Логгировать изменения абсолютно всех свойств никто не будет, более того, некоторые значения нельзя логгировать по требованиям ИБ.
И тут, кроме отладки, вариантов почти не остается. Есть ещё второй способ — обратное разворачивание всей этой операции. Ну т.е. идти от обратного. Свойство В оказалось таким-то, какие предпосылки могли быть, а как мы могли придти к ним и так далее.
sand14
06.05.2018 21:20Это все хорошо — предложенная роль логгирования в разработке и механизмы реализации этой роли.
При этом, как и все хорошие практики, предложенный подход имеет некоторые недостатки (точнее, это не недостатки, а следствие состояния индустрии):
Такие практики ведут к тому, что эффект от них проявляется в средне- и долгосрочной перспективах.
Если постараться — эффект можно получить даже в ближней перспективе.
Но руководству фичи нужны здесь и сейчас, даже если потом все сломается и/или будет глючить, и время и цена сопровождения фич растянутся на годы.
Отсюда следуют и другие моменты.
Например: «Коллегам приходится смотреть не только на сам алгоритм, но и на трассировку его выполнения».
Т.е., коллегам для работы с вашей фичей нужно будет соблюдать определенную методологию.
Будут ли они ее соблюдать, тем более в ситуации, когда это от вас не зависит (например, опять же, когда от них будут требовать быстрых выдачи фич на гора и закрытия тасок)?
Ну и если уж заговорили о методологии, то, если соблюдать определенные методологии (т.е., если в принципе их получится соблюдать на проекте) на самом раннем этапе — этапе проектирования и написания кода — условно, тот же SOLID (до кучи можно о многом поговорить — и о понимании сложностей O(N), иммутабельности и прочем), то необходимость в отладке (дебаге) и логгировании драматически сокращается.
Хотя конечно, это не отменяет отладку и логгирование как таковые.
vedenin1980
06.05.2018 22:56Во-перых, тут смешиваются тест и логи, по-хорошему есть 3 способа узнать что происходит с кодом:
1. Написать тесты,
2. Добавить логи,
3. Включить отладку,
Во-вторых, судя по всему отладку просто используют неправильно, отладка нужна для того, чтобы написал тесты, написал код к этим тестам — проверил работоспособность, не работает — отладил. Бессмысленно добавлять тонны логов, которые после того как код будет написан — не понадобятся.
Отладка зло только если пытатесь отлаживать сразу все приложение, когда вы отлаживаете один unit тест — она. позволяет писать код в разы быстрее, чем поиск ошибок через логирование.
В-третих, логирование увеличивает кол-ва кода в приложении и «загрязняет» бизнес код, что идет в разрез сразу многим принципам чистого кода, не пишите того что вам не нужно и т.д. Логирование должно быть только там где оно потенциально нужно и важно, иначе у вас логирования ненужного поведения будет больше чем собственно кода. По хорошему, вместо логирования стоит использовать всякие AOP и т.п. техники, чтобы не забивать собственно код приложения.
Siemargl
06.05.2018 23:27Слишком поверхностно.
1. Логгирование типовыми/хорошими библиотеками есть настраиваемое (см комменты, но не код в статье)
2. Выкидывать дополнительный способ отладки — зачем? Давайте лучше отрежем руку.
3. Классика DbC и подобные техники. Рекомендую почитать возможности D
P.S. Асинхронное логгирование в многопоточке — то еще гадание на кофе
nporaMep
07.05.2018 03:47Хороший совет, и даже те кто пишут про СОЛИД и тестируемый код — всегда будет какой-нить ньюхайр, который придет в многолетний код и пофиксит баг и не покроет его новыми тестами или не подумает о каком-нибудь пограничном сценарии. И потом это упадёт в продакшне у клиента и удачи вам понимать почему это произошло.
В реальном продакшне производительность может страдать, поэтому флаг/опция на уровень логгирования обязателен.
Еще у всяких фреймворков типа NLog есть оверлоады на лямбды применимые даже к вашему примеру:
_log.Trace($«Privilege: {privilege} not added to User: {user}»);
user тут объект, т.е. ожидаю что в нём перекрыт ToString который может быть еще довольно большой строкой. Также довольно удобно просто писать что-нибудь типа JsonConvert.Serialize(user), чтобы в логах почитать можно было. Поэтому лучше писать это так:
_log.Trace(() => $«Privilege: {privilege} not added to User: {user}»);
lxsmkv
07.05.2018 03:51У нас в системе используется DSL который вообще не имеет режима живого дебаггинга. Так что там только логгирование и помогает.
vikarti
07.05.2018 08:11Мобильная разработка iOS/Android. Очень помогает логгирование как при обычной разработке (на машине разработчика запущен спецклиент, с выбором уровней логгирования, тегов (обычно — конкретных классов) и так далее) и в продакшене (в случае падения(или 'падения' — можно ведь отослать фейковый exception) в Crashlytics будут последние 64 Kb логов).
Если совсем все плохо в продакшене и требования ИБ это допускают — подключается через специальный адаптер Amplitude с ее возможностями user path отслеживать.
prs123
07.05.2018 14:59Логгирование это конечно хорошо, но вот выкидывать дебуг — по-моему это перебор. К примеру, есть чудно-замечательный язык Swift (да, тот самый, который для разработки под iOS). Так вот, я так и не понял, как можно перехватить в нём фатальные ошибки через логирование, а не через вывод в лог-окно в режиме дебага?
Конечно, если кто направит на путь истинный, буду благодарен
potan
07.05.2018 17:18-1Еще бы иметь развитый язык запростов для анаиза логов. Что-то типа SPARQL, а не полнотекстовый поиск с регулярными выражениями.
Bronx
08.05.2018 11:45-1Мысли правильные. Единственно, неплохо бы разделять logging (средство аудита) и tracing (средство диагностики).
michael_vostrikov
08.05.2018 13:32+1Просто залогируйте состояние нужных вам объектов при определённых условиях на определённой итерации цикла.
Ага, потом на чтение и поиск нужной строчки среди записей о success-варианте уйдет больше времени, чем весь цикл вручную с F10 пробежать.
_log.Trace($"Remote role: {roleInOtherService}")Как логирование поможет узнать причину, почему
roleInOtherService = null?
Почему-то априори предполагается, что на отладку уходит больше времени. Наоборот, не раз замечал, если с var_dump() за 1-2 раза не получилось найти причину, лучше сразу отладчик включить.
Не надо противопоставлять логи и отладчик. Они дополняют друг друга. Логи помогают установить факт наличия ошибки в логике выполнения, а пошаговая отладка помогает найти ее причину. Анализируя логи, мы тоже делаем отладку, только мысленно. Если наше представление о коде неправильное или недостаточное, то такая мысленная отладка может не дать результата.
mapron
Поддерживаю автора, умение писать исчерпывающие трейсы в действительно важных местах дорогого стоит.
Хочу дополнить по тому когда стоит применять подход — если логика вашего приложения зависит от большого количества точек возможного отказа + получить логи намного проще чем воспользоваться удаленной отладкой/собрать краш дамп.
В качестве альтернативы 2 минусу «в продакшене много логов» — можно применить подход «ключ/опция для включения трейс-логов». Если проблема воспроизводится, но только в среде клиента — просим его запустить с определенной опцией.
4 минус вообще не понял — речь о ревью?
as94 Автор
4 минус о том, что есть строчка _log.Trace("..."), которая сама по себе не является частью алгоритма, но в коде присутствует. Это немного захламляет код. Иногда лечится AOP.
Спасибо за мнение.
kalininmr
в С/С++ вполне успешно решается дефайнами. в других ЯП — сложнее
DistortNeo
В C# тоже дефайны есть.
Но для C# есть и другой вариант: писать
Log.Trace?.Text(...)Если объект
Log.Trace == null, то выражение не будет вычисляться, тем самым сохраняя драгоценное cputime.kalininmr
а проверка компилтайм или рантайм?
poxvuibr
А как дефайны решают эту проблему?
kalininmr
для продакшина делаешь пустой дефайн для лога.
для дебага — не делаешь.
poxvuibr
Проблему захламлённости кода это не решает, код как был захламлённым, так и остался.
kalininmr
многие IDE умеют фолдить код по маске
poxvuibr
Фолдить так, чтобы от кода оставалась только одна строчка и можно было щёлкнуть на плюсик рядом с ней, чтобы раскрыть весь блок?
kalininmr
типа того. по разному.
мне нравится, когда просто полоска со значком.
вот например так в jetbrains продуктах:
blog.jetbrains.com/idea/2012/03/custom-code-folding-regions-in-intellij-idea-111
www.jetbrains.com/help/idea/code-folding.html
poxvuibr
Макрос с трейсом как правило и занимает одну строку, так что в данном конкретном случае фолдинг мало чем поможет.
kalininmr
непомню где, но видел что скрывалось совсем.
просто серая полоска между строчками. возможно в VS
hanzakkerman
При написании кода на компилируемых языках имеет смысл компилировать код с учётом «максимально допустимого уровня отладки». Т.е. оставлять пользователю возможность менять уровень логирования, но -лишь в определённых пределах. Именно уровень trace следует убирать условной компиляцией в первую очередь: это не только не должно быть нужно заказчику, если, конечно, он не является вашей «лабораторной мышью» для экспериментов, но и запросто может скомпрометировать ваш код или даже послужить источником весьма впечатляющих дыр в безопасности приложения (элементарный пример дампа в лог с неверно настроенными правами доступа структуры, содержащей заботливо расшифрованный пароль из конфига, я думаю, приводить не надо). К сожалению, есть и некий гипотетический негативный эффект от компиляции с «вырезанием» всего ненужного конечному покупателю кода: в многопоточных и асинхронных приложениях это может приводить к неприятному эффекту смещения таймингов исполнения, проявляющемуся в том, что при «правильно заклинивших в одном положении закрылках», т.е. в режиме отладки со включенными log.trace'ами всё будет работать отлично и всегда, а вот в режиме, когда отдельные участки многопоточного кода перестанут вдруг синхронизироваться на записи в один и тот же файл — 1 раз на 100 приложение вдруг начнёт вываливаться «в корку».
В целом давно ждал подобную статью, сам довольно много размышлял над подходами к отладке — и выбрал для себя именно отладку логированием.