Вам еще не надоело писать 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)


  1. Sabubu
    13.04.2019 15:36
    +5

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

    Если же у вас происходит какая-то ошибка, то не удобнее ли использовать отладчик? Ну или натыкать несколько console.log, которые сразу же удалить после отладки?


    1. keenondrums Автор
      13.04.2019 15:43

      С помощью декоратора Log мы явно помечаем какие именно методы должны быть залоггированы. Никто не обязывает логгировать все, как вы подметили это имеет мало смысла.
      Как вы будете использовать отладчик с продакшне? Для того, чтобы понять, что поломалась и при каких условиях, надо какие-то основные моменты жизни того же хттп запроса залоггировать. Эта библиотека призвана сделать именно это. Только вместо того, чтобы писать каждый раз ручками само сообщение, позаботившись о правильном форматировании и сериализации, вы можете делегировать это class-logger


      1. ReklatsMasters
        13.04.2019 16:17

        надо какие-то основные моменты жизни того же хттп запроса залоггировать

        Для этого есть postmortem debugging.


        1. keenondrums Автор
          13.04.2019 16:21

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


          1. Sabubu
            14.04.2019 18:58

            Я обычно в PHP просто при возникновении исключения пишу в лог не только исключение (и его стектрейс), но и параметры HTTP-запроса. Соответственно, потом мы можем по этим данным элементарно найти, что это был за запрос, какой контроллер этот запрос обрабатывал и посмотреть по коду, что там могло пойти не так. А если исключения не возникло — значит все в порядке, и логи засорять незачем.

            Плюс, в PHP есть проверка типов, которая обычно такие случаи отлавливает рядом с местом возникновения. В JS, кстати, тоже Typescript и Flow есть. Даже если ее нет, вместо малополезного логгирования вы можете проверять, что вернула та или иная функция и выбрасывать исключение, если что-то не так. Чтобы сразу увидеть проблему.

            Логгирование, по моему, бесполезная идея. Если у вас на продакшене идет 10 запросов в секунду, у вас же лог будет гигабайт весить к концу дня. Какой смысл записывать столько информации, и кто ее будет разгребать, непонятно.

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


            1. keenondrums Автор
              14.04.2019 19:17

              Можно логгировать с разным уровнем, чтобы в той же кибане это удобно фильтровать. Так же можно добавить к запросу traсe ID, чтобы по этому самому trace ID удобно отследить его жизненный цикл. Я и не предлагаю логгировать все, ровно необходимый минимум. Да и если даже логгировать много, при наличии trace ID логи фильтруются на раз.
              Дело в том, что если есть касакад из сервисов, которые каким-либо образом данные меняют и передают друг другу, то одного стек трейса может быть мало. Вот сервис №10 плюнул мне ошибкой, что, мол, ждли строку, а пришел undefined. А толку, если у меня до этого данные прошли через 9 других сервисов? Где именно они поломались?


  1. Aries_ua
    13.04.2019 23:14

    А теперь тоже самое, но не использовать в зависимостях 'reflect-metadata'. Думаю для обучение так же будет самое оно. :)


    1. justboris
      13.04.2019 23:34

      Согласен, reflect-metadata — огромный пакет. Можно заменить его на более легкую альтернативу: https://github.com/abraham/reflection


      1. keenondrums Автор
        14.04.2019 00:03

        reflect-metadata здесь peer зависимость. По идее можно использовать предложенную вами альтернативу при желании. АПИ у них вроде совместимый.
        Из плюсов reflect-metadata — он уже включён в angular. На стороне же NodeJS размер модуля вообще значения не имеет.


    1. keenondrums Автор
      14.04.2019 00:05

      Дык особо ничего и не поменяется. Просто будем свои навелосепедированные символы в property descriptor добавлять :)


      1. Aries_ua
        14.04.2019 08:58

        Почему не поменяет, как раз наоборот. Так как автор собрал пакет, и написал что он это сделал как для обучения, так и для использования, то почему бы не разобраться с reflect-metadata. Понятно что велосипед, но очень полезный для опыта.


  1. SergioShpadi
    14.04.2019 09:44
    +1

    Воистину, Java-программист может написать программу на Java на любом языке программирования


  1. codemafia
    14.04.2019 10:25

    image


  1. meded90
    14.04.2019 18:52

    Недавно такуюже штуку хотел написать
    оч удобно когда большое количество асинхроных вызово и не понятно когда что дергается

    Круто былобы добавить еще нейм спейсы чтобы легко отключать части прложения от логирования как сделоано вот тут www.npmjs.com/package/debug и крутая фича с треконем времени


    1. 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 {}


  1. storm_r1der
    14.04.2019 18:52

    del


    1. keenondrums Автор
      14.04.2019 18:55

      Вы можете переопределить formatter и логгировать ровно то, что вам нужно
      github.com/keenondrums/class-logger#formatting

      Логгрование ошибок есть.

      Сериализованная ошибка включает в себя следующие свойства:
      — Имя класса (функции), которая была использована для создания ошибки (error.constructor.name).
      — Код (error.code).
      — Сообщение (error.message).
      — Имя (error.name).
      — Стек трейс (error.stack).