Site icon 8HOST.COM

Логирование приложения Node.js с помощью Winston

Amber

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

Winston включает поддержку нескольких вариантов хранения и уровней логов, запросы логов и даже встроенный профилировщик. В этом мануале вы узнаете, как использовать Winston для логирования приложения Node/Express, которое мы создадим в рамках этого процесса. Также вы узнаете, как объединить Winston с другим средством логирования программного обеспечения HTTP для Node.js под названием Morgan – это позволяет объединить логи данных HTTP-запросов с другой информацией.

В результате у вас будет сервер Ubuntu, на котором будет работать простое приложение Node/Express.

Требования

1: Создание базового приложения Node/Express

Обычно Winston используется для логирования событий веб-приложений, созданных с помощью Node.js. Чтобы научится настраивать Winston, создайте простое веб-приложение Node.js, используя платформу Express. Чтобы запустить базовое веб-приложение, можно использовать express-generator, инструмент командной строки для быстрого запуска веб-приложения Node/Express. Поскольку (согласно требованиям) вы установили Node Package Manager, вы можете использовать команду npm для установки express-generator. Также можно использовать флаг -g, который устанавливает пакет глобально, чтобы он мог использоваться как инструмент командной строки вне существующего проекта или модуля Node. Установите пакет с помощью следующей команды:

sudo npm install express-generator -g

Установив express-generator, вы можете создать приложение с помощью команды express, указав имя каталога, который вы хотите использовать для проекта. Это создаст приложение и все, что нужно для начала работы:

express myApp

Затем установите Nodemon, который будет автоматически перезагружать приложение всякий раз, когда вы вносите какие-либо изменения. Приложение Node.js необходимо перезапускать после внесения любых изменений в исходный код, чтобы эти изменения вступили в силу. Nodemon будет автоматически следить за изменениями и перезапускать приложение. Чтобы использовать nodemon в качестве инструмента командной строки, установите его с помощью флага -g:

sudo npm install nodemon -g

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

cd myApp
npm install

По умолчанию приложения, созданные с помощью express-generator, запускаются по порту 3000, поэтому нужно убедиться, что порт не заблокирован брандмауэром. Чтобы открыть порт 3000, выполните следующую команду:

sudo ufw allow 3000

Теперь у вас есть все необходимое для запуска веб-приложения. Для этого запустите следующую команду:

nodemon bin/www

Это запускает приложение по порту 3000. Мы можете проверить его работу, перейдя по ссылке http://your_server_ip:3000 в веб-браузере. Вы должны увидеть что-то вроде этого:

Express
Welcome to Express!

В этот момент нужно запустить вторую сессию SSH на вашем сервере. Работа во второй сессии будет идти во всей оставшейся части этого мануала, а веб-приложение останется в первой сессии. Первая сессия, в которой запущено приложение, будет называться сессией А, а вторая (рабочая) – сессией Б. Если не указано иное, все остальные команды в мануале нужно запускать в сессии Б.

2: Кастомизация приложения Node.js

Приложение по умолчанию, созданное в express-generator, отлично подходит для тестирования, и даже включает в себя связующее ПО Morgan, которое мы будем использовать для регистрации данных о HTTP-запросах. И поскольку Morgan поддерживает выходные потоки, он отлично сочетается с встроенной поддержкой потока Winston, что позволяет объединить логи данных HTTP-запросов с другими данными Winston.

По умолчанию в шаблоне express-generator при ссылке на пакет morgan используется переменная logger. Поскольку вы будете использовать morgan и winston, а оба они являются пакетами логирования, вы можете запутаться, если один из них будет называться logger. Измените это, отредактировав файл app.js в корне проекта.

nano ~/myApp/app.js

В начале файла будет такая строка:

...
var logger = require('morgan');
...

Измените ее так:

...
var morgan = require('morgan');
...

Также нужно в файле переменную logger и изменить ее на morgan. Пока вы находитесь в этом файле, измените также формат логов, используемый пакетом morgan, на combined, который является стандартным форматом логов Apache; это добавит в логи полезную информацию (удаленный IP-адрес, заголовок HTTP-запроса).

Найдите строку:

...
app.use(logger('dev'));
...

И измените ее:

...
app.use(morgan('combined'));
...

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

Выйдите и сохраните файл (CTRL-X, затем Y, а затем ENTER).

3: Установка и настройка Winston

Теперь можно установить и настроить Winston. На этом этапе мы рассмотрим некоторые параметры конфигурации, которые доступны как часть пакета winston, и создадим регистратор, который будет записывать информацию в файл и консоль.

Чтобы установить winston, запустите следующую команду:

cd ~/myApp
npm install winston

Вспомогательные файлы или утилиты для приложений полезно хранить в специальном каталоге, поэтому создайте каталог config, который будет содержать конфигурацию winston:

mkdir ~/myApp/config

Теперь создайте файл, который будет содержать конфигурацию winston,

touch ~/myApp/config/winston.js

Затем создайте папку, в которой будут храниться ваши файлы логов:

mkdir ~/myApp/logs

Наконец, установите пакет app-root-path, который полезен при настройке путей в Node.js. Этот пакет напрямую не связан с Winston, но очень помогает при указании путей к файлам в коде Node.js. Мы будем использовать его, чтобы указать расположение файлов лога Winston из корня проекта и упростить синтаксис пути:

npm install app-root-path --save

Все необходимое для настройки логирования теперь есть на вашем сервере, поэтому можно перейти к определению параметров конфигурации. Откройте ~/myApp/config/winston.js для редактирования:

nano ~/myApp/config/winston.js

Затем добавьте пакеты app-root-path и winston.

var appRoot = require('app-root-path');
var winston = require('winston');

Используя эти переменные, вы можете определить параметры конфигурации для транспортов. Транспорты – это понятие Winston, которое ссылается на механизмы хранения/вывода логов. Winston поставляется с тремя основными транспортами – консолью, файлом и HTTP. Сосредоточим внимание на консоли и файлах: консольный транспорт будет записывать информацию на консоль, а файловый будет писать информацию в указанный файл. Каждое определение транспорта может содержать собственные параметры конфигурации, такие как размер файла, уровни и формат логов. Вот краткое описание настроек, которые нужно использовать для каждого транспорта:

Уровни логирования определяют приоритет сообщения и обозначаются целым числом. Winston использует уровни логирования npm, где 0 имеет наивысший приоритет.

При указании уровня логирования будут регистрироваться записи этого уровня и всех уровней с более высоким приоритетом. Например, указав уровень 2, вы соберете в лог все сообщения уровней 0, 1 и 2. Уровни логирования указываются при вызове регистратора; то есть чтобы записать ошибки, нужно ввести: logger.error(‘test error message’).

Чтобы определить транспорты file и console в конфигурации winston, используйте такой код:

...
var options = {
file: {
level: 'info',
filename: `${appRoot}/logs/app.log`,
handleExceptions: true,
json: true,
maxsize: 5242880, // 5MB
maxFiles: 5,
colorize: false,
},
console: {
level: 'debug',
handleExceptions: true,
json: false,
colorize: true,
},
};

Затем создайте новый регистратор winston с транспортом file и console, используя свойства, определенные в переменной options:

...
var logger = new winston.Logger({
transports: [
new winston.transports.File(options.file),
new winston.transports.Console(options.console)
],
exitOnError: false, // do not exit on handled exceptions
});

По умолчанию morgan выводит данные только на консоль, поэтому сейчас нужно определить функцию потока, которая сможет собрать вывод morgan в файлы логов winston. Используйте уровень логирования info, чтобы вывод был загружен обоими транспортами:

...
logger.stream = {
write: function(message, encoding) {
logger.info(message);
},
};

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

...
module.exports = logger;

В результате конфигурации winston должны выглядеть следующим образом:

var appRoot = require('app-root-path');
var winston = require('winston');
// define the custom settings for each transport (file, console)
var options = {
file: {
level: 'info',
filename: `${appRoot}/logs/app.log`,
handleExceptions: true,
json: true,
maxsize: 5242880, // 5MB
maxFiles: 5,
colorize: false,
},
console: {
level: 'debug',
handleExceptions: true,
json: false,
colorize: true,
},
};
// instantiate a new Winston Logger with the settings defined above
var logger = new winston.Logger({
transports: [
new winston.transports.File(options.file),
new winston.transports.Console(options.console)
],
exitOnError: false, // do not exit on handled exceptions
});
// create a stream object with a 'write' function that will be used by `morgan`
logger.stream = {
write: function(message, encoding) {
// use the 'info' log level so the output will be picked up by both transports (file and console)
logger.info(message);
},
};
module.exports = logger;

Сохраните и закройте файл.

4: Интеграция Winston в приложение

Чтобы регистратор работал в вашем приложении, необходимо сообщить о нем express. В разделе 2 конфигурация express была помещена в файл app.js. Импортируйте регистратор в этот файл. Откройте файл для редактирования, выполнив:

nano ~/myApp/app.js

Импортируйте winston в начале файла:

...
var winston = require('./config/winston');
...

Первое место, где мы будем использовать winston, – это morgan. Используйте опцию stream  и настройте ее на интерфейс потока, который вы создали как часть конфигурации winston. Для этого найдите следующую строку:

...
app.use(morgan('combined'));
...

Измените это:

...
app.use(morgan('combined', { stream: winston.stream }));
...

Сохраните и закройте файл.

Теперь можно увидеть некоторые данные логов. Если вы перезагрузите страницу в веб-браузере, в консоли SSH-сессии А вы увидите такой вывод:

[nodemon] restarting due to changes...
[nodemon] starting `node bin/www`
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:29:36 +0000] "GET / HTTP/1.1" 304 - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:29:37 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://167.99.4.120:3000/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

Здесь есть две записи: первая для запроса на HTML-страницу, вторая для сопровождаемой таблицы стилей. Поскольку каждый транспорт поддерживает уровень логирования info, вы также должны увидеть аналогичную информацию в файле ~/myApp/logs/app.log. Однако вывод должен быть записан как объект JSON, поскольку вы указали json: true в конфигурации транспорта file.

Читайте также: Основы работы с JSON

Чтобы просмотреть содержимое лога, выполните следующую команду:

tail ~/myApp/logs/app.log
{"level":"info","message":"::ffff:72.80.124.207 - - [07/Mar/2018:17:29:36 +0000] \"GET / HTTP/1.1\" 304 - \"-\" \"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36\"\n","timestamp":"2018-03-07T17:29:36.962Z"}
{"level":"info","message":"::ffff:72.80.124.207 - - [07/Mar/2018:17:29:37 +0000] \"GET /stylesheets/style.css HTTP/1.1\" 304 - \"http://167.99.4.120:3000/\" \"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36\"\n","timestamp":"2018-03-07T17:29:37.067Z"}

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

Пакет express-generator по умолчанию включает страницы ошибок 404 и 500. Откройте файл ~/myApp/app.js:

nano ~/myApp/app.js

Найдите в конце файла такой блок кода:

...
// error handler
app.use(function(err, req, res, next) {
// set locals, only providing error in development
res.locals.message = err.message;
res.locals.error = req.app.get('env') === 'development' ? err : {};
// render the error page
res.status(err.status || 500);
res.render('error');
});
...

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

Поскольку сейчас вы работаете с ошибками, используйте уровень логирования error. Опять же, оба транспорта настроены на запись сообщений об ошибках, поэтому вы должны увидеть вывод в логах console и file. Вы можете включать в лог всю необходимую информацию, поэтому обязательно включите:

Обновите маршрут обработчика ошибок:

...
// error handler
app.use(function(err, req, res, next) {
// set locals, only providing error in development
res.locals.message = err.message;
res.locals.error = req.app.get('env') === 'development' ? err : {};
// add this line to include winston logging
winston.error(`${err.status || 500} - ${err.message} - ${req.originalUrl} - ${req.method} - ${req.ip}`);
// render the error page
res.status(err.status || 500);
res.render('error');
});
...

Выйдите и сохраните файл.

Чтобы проверить этот код, попробуйте получить доступ к несуществующей странице, что вызовет ошибку 404. Вернитесь в свой веб-браузер, попробуйте загрузить следующий URL-адрес: http://your_server_ip:3000/foo. Приложение уже может отреагировать на такую ошибку благодаря шаблону, созданному express-generator. В браузере должно появиться подобное сообщение об ошибке (ваше сообщение может быть более подробным):

Not found

Теперь еще раз посмотрите на консоль в сессии A. В логе должна быть запись об ошибке, и благодаря цветному выводу ее можно легко найти.

[nodemon] starting `node bin/www`
error: 404 - Not Found - /foo - GET - ::ffff:72.80.124.207
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:40:11 +0000] "GET /foo HTTP/1.1" 404 985 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"
info: ::ffff:72.80.124.207 - - [07/Mar/2018:17:40:11 +0000] "GET /stylesheets/style.css HTTP/1.1" 304 - "http://167.99.4.120:3000/foo" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/64.0.3282.186 Safari/537.36"

Что касается регистратора файлов, его можно снова проверить с помощью tail:

tail ~/myApp/logs/app.log

Появится следующее сообщение:

{"level":"error","message":"404 - Not Found - /foo - GET - ::ffff:72.80.124.207","timestamp":"2018-03-07T17:40:10.622Z"}

Сообщение об ошибке включает все данные, которые вы поручили winston регистрировать как часть обработчика ошибок, включая состояние ошибки (404), запрошенный URL (localhost/foo), метод запроса (GET), отправивший запрос IP-адрес и метку времени отправки запроса.

Заключение

Winston поддерживает еще много полезных функций. Вы можете настроить более сложную систему логирования – по мере усложнения приложения это станет необходимо. Рекомендуем вам взглянуть на эти ссылки: