Вам еще не надоело писать logger.info('ServiceName.methodName.')
и logger.info('ServiceName.methodName -> done.')
на каждый чих? Может вы, так же как и я, неоднократно задумывались о том, чтобы это дело автоматизировать? В данной статье рассказ пойдет о class-logger, как об одном из вариантов решения проблемы с помощью всего лишь двух декораторов.
Зачем оно вообще надо?
Не все перфекционисты — инженеры, но все инженеры — перфекционисты (ну, почти). Нам нравятся красивые лаконичные абстракции. Мы видим красоту в наборе кракозябликов, которые человек неподготовленный и прочитать не сможет. Нам нравится чувствовать себя богами, создавая микро-вселенные, которые живут по нашим правилам. Предположительно, все эти качества берут начало из нашей необъятной лени. Нет, инженер не боится работы как класса, но люто ненавидит рутинные повторяющиеся действия, которые руки так и тянутся автоматизировать.
Написав несколько тысяч строк кода, предназначенного только лишь для логгирования, обычно мы приходим к созданиям каких-то своих паттернов и стандартов написания сообщений. К сожалению, нам все еще приходится применять эти паттерны вручную. Главное "зачем" class-logger — предоставить декларативный конфигурируемый способ простого логгирования шаблонных сообщений при создании класса и вызове его методов.
Шашки наголо!
Не бродя вокруг да около, перейдем сразу к коду.
import { LogClass, Log } from 'class-logger'
@LogClass()
class ServiceCats {
@Log()
eat(food: string) {
return 'purr'
}
}
Этот сервис создаст три записи в логе:
- Перед его созданием со списком аргументов, переданных в конструктор.
- Перед вызовом
eat
со списком аргументов. - После вызова
eat
со списком аргументов и результатом выполнения.
In words of code:
// Логгирует перед созданием ServiceCats
// `ServiceCats.construct. Args: [].`
const serviceCats = new ServiceCats()
// Логгирует перед вызовом `eat`
// `ServiceCats.eat. Args: [milk].`
serviceCats.eat('milk')
// Логгирует после вызова `eat`
// `ServiceCats.eat -> done. Args: [milk]. Res: purr.`
Полный список событий, которые можно залоггировать:
- Перед созданием класса.
- Перед вызовом синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
- После вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
- Ошибки вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
Функциональное свойство — стрелочная функция присвоенная свойству (class ServiceCats { private meow = () => null }
). Наиболее часто используется для сохранения контекста выполнения (this
).
Нам обещали "конфигурируемый" способ логгирования
class-logger три уровня иерархии конфигурации:
- Глобальный
- Класс
- Метод
При вызове каждого метода, все три уровня мержатся вместе. Библиотека предоставляет разумный глобальный конфиг по умолчанию, так что ее можно использовать и без какой-либо предварительной настройки.
Глобальный конфиг
Он создается для всего приложения. Его можно переопределить с помощью setConfig
.
import { setConfig } from 'class-logger'
setConfig({
log: console.info,
})
Конфиг класса
Он свой для каждого класса и применяется для всех методов этого класса. Может переопределять глобальный конфиг.
import { LogClass } from 'class-logger'
setConfig({
log: console.info,
})
@LogClass({
// Переопределяет глобальный конфиг для этого сервиса
log: console.debug,
})
class ServiceCats {}
Конфиг метода
Работает только для самого метода. Имеет приоритет над конфигом класса и глобальным конфигом.
import { LogClass } from 'class-logger'
setConfig({
log: console.info,
})
@LogClass({
// Переопределяет глобальный конфиг для этого сервиса
log: console.debug,
})
class ServiceCats {
private energy = 100
@Log({
// Переопределяет конфиг класса только для этого метода
log: console.warn,
})
eat(food: string) {
return 'purr'
}
// Этот метод использует `console.debug` предоставленный конфигом класса
sleep() {
this.energy += 100
}
}
Что можно конфигурировать?
Мы рассмотрели как изменять конфиг, но все еще не разобрали, что именно в нем можно изменить.
Здесь можно найти много примеров конфигурационных объектов для разных случаев.
Ссылка на интерфейс, если вы понимаете TypeScript лучше. чем русский :)
Объект конфигурации имеет следующие свойства:
log
Это функция, которая занимается, собственно, логгированием. Ей на вход приходит отформатированное сообщения в виде строки. Используется для логгирования следующих событий:
- Перед созданием класса.
- Перед вызовом синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
- После вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
По умолчанию console.log
.
logError
Это функция, которая тоже занимается логгированием, но уже только сообщений об ошибке. Ей также на вход приходит отформатированное сообщения в виде строки. Используется для логгирования следующих событий:
- Ошибки вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
По умолчанию console.error
.
formatter
Это объект с двумя методами: start
и end
. Эти методы создают то самое отформативанное сообщение.
start
создает сообщения для следующих событий:
- Перед созданием класса.
- Перед вызовом синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
end
создает сообщения для следующих событий:
- После вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
- Ошибки вызова синхронных и асинхронных методов и функциональных свойств, как статических, так и не статических.
По умолчанию new ClassLoggerFormatterService()
.
include
Конфиг того, что должно быть включено в конечное сообщение.
args
Это может быть как булево значение, так и объект.
Если это boolean
, то он задает включать ли список аргументов (помните Args: [milk]
?) во все сообщения (start
и end
).
Если это объект, то у него должно быть два булевых свойства: start
и end
. start
задает включать ли список аргументов для start
сообщений, end
— для end
сообщений.
По умолчанию true
.
construct
Это boolean
, который контролирует логгировать ли создание класса или нет.
По умолчанию true
.
result
Это boolean
, который контролирует логгировать возвращаемое из метода значение. Стоит заметить, что возвращаемое значение — это не только то, что метод возвращает при успешном выполнении, но и ошибка, которую он бросает в случае неудачного выполнения. Помните Res: purr
? Если этот флаг будет false
, то не будет никакого Res: purr
.
По умолчанию true
.
classInstance
Это может быть как булево значение, так и объект. Концепция та же, что и include.args
.
Добавляет сериализованное представление инстанса вашего класса в сообщения. Другими словами, если у вашего класса есть какие-то свойства, то они будут сериализованны в JSON и добавлены в логи.
Не все свойства подлежат сериализации. class-logger использует следующую логику:
- Берем все собственные (те, которые не в прототипе) свойства интсанса.
- Почему? Очень редко прототип меняет динамически, так что нет большого смысла логгировать его содержимое.
- Выкидываем из них все типа
function
.
- Почему? Чаще всего свойства типа
function
— это просто стрелочные функции, которые не сделали обычными методами ради сохранения контекста (this
). Они редко имеют динамическую природу, так что и логгировать их нет смысла.
- Почему? Чаще всего свойства типа
- Выкидываем из них все объекты, которые не являются простыми объектами.
- Что за простые объекты?
ClassLoggerFormatterService
считает объект простым, если его прототип — этоObject.prototype
. - Почему? Часто в качестве свойств выступают инстансы других классов-сервисов. Наши логи распухли бы самым безобразным образом, если бы мы из стали сериализовать.
- Что за простые объекты?
- Сериализовать в JSON строку все, что осталось.
class ServiceA {}
@LogClass({
include: {
classInstance: true,
},
})
class Test {
private serviceA = new ServiceA()
private prop1 = 42
private prop2 = { test: 42 }
private method1 = () => null
@Log()
public method2() {
return 42
}
}
// Логгирует перед созданием `Test`
// 'Test.construct. Args: []. Class instance: {"prop1":42,"prop2":{"test":42}}.'
const test = new Test()
// Логгирует перед вызовом `method2`
// 'Test.method2. Args: []. Class instance: {"prop1":42,"prop2":{"test":42}}.'
test.method2()
// Логгирует после вызова `method2`
// 'Test.method2 -> done. Args: []. Class instance: {"prop1":42,"prop2":{"test":42}}. Res: 42.'
По умолчанию false
.
Берем полный контроль над форматированием сообщений
Что же делать, если вам нравится идея, но ваши представление о прекрасном настаивает на другом формате строки сообщений? Вы можете взять полный контроль над форматированием сообщений, передав свой собственный форматтер.
Вы можете написать свой собственный форматтер с нуля. Безусловно. Но этот вариант не будет освещен в рамках этой (если вам интересна именно эта опцию, загляните в раздел "Formatting" в README).
Самый быстрый и простой способ переопределить форматирование — это унаследовать свой форматтер от форматтера по умолчанию — ClassLoggerFormatterService
.
ClassLoggerFormatterService
имеет следующие protected
методы, которые создают небольшие блоки финальных сообщений:
base
- Возвращает имя класса и имя метода. Пример:
ServiceCats.eat
.
- Возвращает имя класса и имя метода. Пример:
operation
- Возвращает
-> done
или-> error
в зависимости от того, успешно ли выполнился метод.
- Возвращает
args
- Возвращает сериализованный список аргументов. Пример:
. Args: [milk]
. Он использует fast-safe-stringify для сериализации объектов под капотом.
- Возвращает сериализованный список аргументов. Пример:
classInstance
- Возвращает сериализованный инстанс класса. Пример:
. Class instance: {"prop1":42,"prop2":{"test":42}}
. Если вы включилиinclude.classInstance
в конфиге, но по какой-то причине сам инстанс в момент логгирования не доступен (например, для статических методов или перед созданием класса), возвращаетN/A
.
- Возвращает сериализованный инстанс класса. Пример:
result
- Возвращает сериализованный результат выполнения или сериализованную ошибку. Использует fast-safe-stringify для объектов под капотом. Сериализованная ошибка включает в себя следующие свойства:
- Имя класса (функции), которая была использована для создания ошибки (
error.constructor.name
). - Код (
error.code
). - Сообщение (
error.message
). - Имя (
error.name
). - Стек трейс (
error.stack
).
final
- Возвращает
.
. Просто.
.
- Возвращает
Сообщение start
состоит из:
base
args
classInstance
final
Сообщение end
состоит:
base
operation
args
classInstance
result
final
Вы можете переопределить только необходимые вам базовые методы.
Давайте рассмотрим, как можно добавить timestamp ко всем сообщениям.
Я не говорю, что это надо делать в реальных проектах. pino, winston и большинство других логгеров способны делать это самостоятельно. Этот пример служит в исключительно образовательных целях.
import {
ClassLoggerFormatterService,
IClassLoggerFormatterStartData,
setConfig,
} from 'class-logger'
class ClassLoggerTimestampFormatterService extends ClassLoggerFormatterService {
protected base(data: IClassLoggerFormatterStartData) {
const baseSuper = super.base(data)
const timestamp = Date.now()
const baseWithTimestamp = `${timestamp}:${baseSuper}`
return baseWithTimestamp
}
}
setConfig({
formatter: new ClassLoggerTimestampFormatterService(),
})
Заключение
Не забывайте следовать инструкциям по установке и ознакомьтесь с требованиями перед тем как использовать эту библиотеку на вашем проекте.
Надеюсь, вы не потратили время зря, и статья была вам хоть чуточку полезна. Просьба пинать и критиковать. Будем учиться кодить лучше вместе.
Комментарии (17)
Aries_ua
13.04.2019 23:14А теперь тоже самое, но не использовать в зависимостях 'reflect-metadata'. Думаю для обучение так же будет самое оно. :)
justboris
13.04.2019 23:34Согласен, reflect-metadata — огромный пакет. Можно заменить его на более легкую альтернативу: https://github.com/abraham/reflection
keenondrums Автор
14.04.2019 00:03reflect-metadata здесь peer зависимость. По идее можно использовать предложенную вами альтернативу при желании. АПИ у них вроде совместимый.
Из плюсов reflect-metadata — он уже включён в angular. На стороне же NodeJS размер модуля вообще значения не имеет.
keenondrums Автор
14.04.2019 00:05Дык особо ничего и не поменяется. Просто будем свои навелосепедированные символы в property descriptor добавлять :)
Aries_ua
14.04.2019 08:58Почему не поменяет, как раз наоборот. Так как автор собрал пакет, и написал что он это сделал как для обучения, так и для использования, то почему бы не разобраться с reflect-metadata. Понятно что велосипед, но очень полезный для опыта.
SergioShpadi
14.04.2019 09:44+1Воистину, Java-программист может написать программу на Java на любом языке программирования
meded90
14.04.2019 18:52Недавно такуюже штуку хотел написать
оч удобно когда большое количество асинхроных вызово и не понятно когда что дергается
Круто былобы добавить еще нейм спейсы чтобы легко отключать части прложения от логирования как сделоано вот тут www.npmjs.com/package/debug и крутая фича с треконем времениkeenondrums Автор
14.04.2019 19:07Трек времени добавить думаю.
Насчет неймспейсов пока не уверен. Если они вам нужны и нравится как оно работает в debug, то почему бы не использовать debug в качестве логгера более никого уровня вместе с class-logger?
// logger.service.ts import debug from 'debug' export const loggerNamespaceA = debug('NamespaceA') export const loggerNamespaceB = debug('NamespaceB') ... // cats.service.ts import { LogClass } from 'class-logger' import { loggerNamespaceA } from './logger.service' @LogClass({ log: loggerNamespaceA, logError: loggerNamespaceA }) class CatsService {}
storm_r1der
14.04.2019 18:52del
keenondrums Автор
14.04.2019 18:55Вы можете переопределить formatter и логгировать ровно то, что вам нужно
github.com/keenondrums/class-logger#formatting
Логгрование ошибок есть.
Сериализованная ошибка включает в себя следующие свойства:
— Имя класса (функции), которая была использована для создания ошибки (error.constructor.name).
— Код (error.code).
— Сообщение (error.message).
— Имя (error.name).
— Стек трейс (error.stack).
Sabubu
Зачем логгировать все вызовы функций? Это же будет генерировать кучу ненужных сообщений. Вам теперь еще придется делать систему сбора и фильтрации логов. Вы в итоге решаете проблемы, которые сами же себе придумали.И так очевидно, что если функцию вызвать, то она будет вызвана. Для этого не требуется лог.
Если же у вас происходит какая-то ошибка, то не удобнее ли использовать отладчик? Ну или натыкать несколько console.log, которые сразу же удалить после отладки?
keenondrums Автор
С помощью декоратора Log мы явно помечаем какие именно методы должны быть залоггированы. Никто не обязывает логгировать все, как вы подметили это имеет мало смысла.
Как вы будете использовать отладчик с продакшне? Для того, чтобы понять, что поломалась и при каких условиях, надо какие-то основные моменты жизни того же хттп запроса залоггировать. Эта библиотека призвана сделать именно это. Только вместо того, чтобы писать каждый раз ручками само сообщение, позаботившись о правильном форматировании и сериализации, вы можете делегировать это class-logger
ReklatsMasters
Для этого есть postmortem debugging.
keenondrums Автор
Не очень понятно как это будет работать для того же речь сервера на NodeJS.
Зачастую просто трейса не хватает. Видно, что пришел undefined, но чтобы понять почему пришел undefined, а не ожидаемый объект, зачастую, надо знать как данные менялись в ключевых моментах обработки запроса.
Sabubu
Я обычно в PHP просто при возникновении исключения пишу в лог не только исключение (и его стектрейс), но и параметры HTTP-запроса. Соответственно, потом мы можем по этим данным элементарно найти, что это был за запрос, какой контроллер этот запрос обрабатывал и посмотреть по коду, что там могло пойти не так. А если исключения не возникло — значит все в порядке, и логи засорять незачем.
Плюс, в PHP есть проверка типов, которая обычно такие случаи отлавливает рядом с местом возникновения. В JS, кстати, тоже Typescript и Flow есть. Даже если ее нет, вместо малополезного логгирования вы можете проверять, что вернула та или иная функция и выбрасывать исключение, если что-то не так. Чтобы сразу увидеть проблему.
Логгирование, по моему, бесполезная идея. Если у вас на продакшене идет 10 запросов в секунду, у вас же лог будет гигабайт весить к концу дня. Какой смысл записывать столько информации, и кто ее будет разгребать, непонятно.
Единственное, что мне приходит в голову — это отладка взаимодействия с внешними сервисами, которые могут не соответствовать собственной документации и присылать кривые данные. Ну не знаю, все равно тут лучше найти время и разобраться с тем, что они присылают. а не писать гигабайты логов, которые никто не прочтет.
keenondrums Автор
Можно логгировать с разным уровнем, чтобы в той же кибане это удобно фильтровать. Так же можно добавить к запросу traсe ID, чтобы по этому самому trace ID удобно отследить его жизненный цикл. Я и не предлагаю логгировать все, ровно необходимый минимум. Да и если даже логгировать много, при наличии trace ID логи фильтруются на раз.
Дело в том, что если есть касакад из сервисов, которые каким-либо образом данные меняют и передают друг другу, то одного стек трейса может быть мало. Вот сервис №10 плюнул мне ошибкой, что, мол, ждли строку, а пришел undefined. А толку, если у меня до этого данные прошли через 9 других сервисов? Где именно они поломались?