Node.js Hata Yönetimi ve Loglama
- Part 1 - Debugging Node.js
- Part 2 - Node.js Hata Yönetimi ve Loglama
Merhaba, "Kontrol Bende" serisine yeni bir konu daha ekliyoruz.
Bundan önce Node.js Debugging konusunu işlemiştik. Şimdi ise hem debugging'te hem de production'da olmazsa olmaz loglama konusuna dalıyoruz.
Loglama konusu node.js ile birlikte daha da önemli bir hale geliyor. Bunun nedeni node.js'in kullanım amaçlarından biri olan scaling'te ne kadar yaşamsal olduğunu bilmemiz.
Şöyle düşünelim. Daha önceden Monolithic mimarideki uygulamalarımızı yönetmek görece kolaydı. Tek bir makinede Uygulama ve DB çalışıyordu ve bakmamız gereken DB üzerindeki bir tablo veya birkaç log dosyasından ibaretti.
Ama microservice'lerin kullanımı, multi-tier uygulamaların kabul görmesi ve scaling ile beraber loglama ve analizi çetrefilli bir hal aldı.
Uygulamanın çoklu makinede (sanal da olabilir) Docker container'lar üzerinde clustered bir yapıda çalışması, redis, mongodb hadoop ve daha nice teknolojinin farklı makinelerde ve hatta yerlerde kurulu olması (cloud computing) bizi logging ve hata yönetiminde radikal çözümler üretmemizi gerektiriyor.
Ancak bu kadar ileri gitmeden önce işleri sırayla yapmalıyız. İlk önceliğimiz node.js uygulamamızdaki logların sağlıklı bir şekilde yazılmasıdır.
Node.js'te bunu başarabilmenin çeşitli yolları mevcut. Ancak uygulama tarafında yapılması zorunlu kısımlar da var. Mesela loglamanın level'lar bazında yapılması. Unhandeled Exception'ların (yakalanmamış istisnalar/hatalar) yönetimi gibi.
Dediğim gibi node.js'te bunun çok farklı yöntemleri mevcut. Benim ilk önereceğim Winston olacak. İsmi de şuradan geliyormuş :/. Bu arada kendisi async loglama yapıyor.
Winston
Kurulum:
1npm install winston --save
2npm install winston-redis --save
Seviyeler
Önemliden önemsize varsayılan seviyeler (levels): error: 0, warn: 1, info: 2, verbose: 3, debug: 4, silly: 5
Kullanımı:
1// varsayılan logger
2var winston = require('winston');
3
4// bu ikisi de aynı
5winston.log('info', 'Hello distributed log files!');
6winston.info('Hello again distributed logs');
Transports
Varsayılan logger'ın winston.transports.Console tipinde varsayılan bir transportu vardır. Yani otomatik olarak çıktıyı Console'a verecektir.
1winston.remove(winston.transports.Console);
2winston.info('Bu hiçbir yere yazılmıyor!');
3
4winston.add(winston.transports.File, { filename: 'logdosyam.log' });
5winston.info('Dosyaya yazacak!');
6
7winston.add(winston.transports.Console);
8winston.info('Hem dosyaya hem console'a yazacak');
Winston official transport'ları çokçadır. HTTP, redis, mongo vb. buradan bulabilirsiniz. Bunun dışında 3rd party zibilyon tane seçenek de mevcuttur.
Metadata
Farklı bilgileri de log'a ekleyebiliyoruz:
1winston.log('info', 'test mesajı', { bilgi: 'bu bir metadatadır' });
Ekleme (interpolation)
Parametreli mesaj yazdırma konusunda yardımcı olur. Parametre tipleri: %s string, %d number, %j json
1var util = require('util');
2
3winston.log('info', 'test mesajı %s %d %j', 'ilk', 5, {number: 123}, {meta: "bu meta" }, function callback(transport, level, msg, meta){
4 console.log("loglama gerçekleşti");
5 console.log(util.format("transport -> %s, level -> %s, mesaj -> %s, meta -> %j", transport, level, msg, meta));
6});
Exceptions
1winston.handleExceptions();
2
3// unhandled exception'ların özel bir dosyaya yazdırılmasını isteyebilirsiniz
4winston.handleExceptions(new winston.transports.File({ filename: 'path/to/exceptions.log' }))
5
6// ya da transport eklerken handleExceptions ile belirtilebiliyor
7// humanReadableUnhandledException ise okunaklı stack trace demek
8winston.add(winston.transports.File, {
9 filename: 'path/to/all-logs.log',
10 handleExceptions: true,
11 level: 'warn',
12 humanReadableUnhandledException: true
13});
14
15// exception logladıktan sonra uygulamadan çıkmasın:
16winston.exitOnError = false;
Üstteki kodda transport level'ı warn olarak ayarlanmış. Bu demektir ki warn ve üzeri önemdeki log'lar verilen transport'a uygulanacak. Bunlar warn, debug ve error'dür. Alt level'lar loglanmayacak: silly ve verbose.
Demo
Konumuzu emektar repository'miz chatcat üzerinden götürmeye kararlıyım :) Spoiler sevenler:
1git clone https://github.com/dhalsim/chatcat.git
2cd chatchat
3git checkout alti
Şeklinde tüm kodları alabilir, veya git checkout bes üzerinden değişiklikleri kendiniz de ekleyebilirsiniz.
Not: Burada önceden belirtmediğim ileri seviye konuları kullanacağım. Bunlar: renklendirme, File için zipleme, tailing ve Redis loglama olacak
src/lib/logging.js:
1var winston = require('winston');
2var moment = require('moment');
3var redis_config = require('src/config').redis;
4var extend = require('src/lib/utils').extend;
5require('winston-redis').Redis;
6
7var redisClient = require('src/lib/redisAdapters/redisConnection').getClient();
8var os = require('os');
9
10var errorMeta = {
11 hostname: os.hostname(),
12 pid: process.pid,
13 memory: process.memoryUsage(),
14 uptime: process.uptime(),
15 env: process.env.NODE_ENV || 'development'
16};
17
18var redisTransport = new (winston.transports.Redis)({
19 redis: redisClient
20});
21
22var errorFileTransport = new (winston.transports.File)({
23 filename: './logs/errors.log',
24 level: 'error',
25 colorize: true,
26 timestamp: function() {
27 return moment.utc().format();
28 },
29 maxsize: 10000, // 10 KB
30 maxFiles: 5,
31 //formatter: function () {},
32 tailable: true,
33 zippedArchive: true
34});
35
36// error: 0, warn: 1, info: 2, verbose: 3, debug: 4, silly: 5
37
38var logger = new (winston.Logger)({
39 transports: [
40 new (winston.transports.Console)({
41 level: 'debug',
42 colorize: true,
43 timestamp: function() {
44 return moment.utc().format();
45 },
46 json: true,
47 prettyPrint: true,
48 humanReadableUnhandledException: true,
49 }),
50 errorFileTransport,
51 redisTransport
52 ]
53});
54
55// log fonksiyonunu override ediyorum
56// error durumunda meta'ya errorMeta'yı inject edeceğim
57logger.log = function(){
58 var args = arguments;
59 var level = args[0];
60
61 if(level === 'error') {
62 var originalMeta = args[2] || {};
63 args[2] = extend(originalMeta, errorMeta);
64 }
65
66 winston.Logger.prototype.log.apply(this,args);
67};
68
69// logger hatası
70logger.on('error', function (err) {
71 console.error('Error occurred', err);
72});
73
74module.exports.log = logger;
75module.exports.loggerMiddleware = function (req, res, next) {
76 req.logger = logger;
77 next();
78};
79module.exports.exceptionMiddleware = function (err, req, res, next) {
80 logger.error(err.message, { stack: err.stack });
81 next(err);
82};
83module.exports.logAndCrash = function (err) {
84 logger.error(err.message, { stack: err.stack });
85 throw err;
86}
3 tane export ettiğim fonksiyonum var. logger genel amaçlı kullanmak için nolur nolmaz koydum. loggerMiddleware, express'te kullanacağım ve req objesine logger property'si inject etmemi sağlayacak. exceptionMiddleware'ı ise hataların yönetilmesi için kullanacağım. next(error) kullanımı bu middleware'e yönlendirecektir.
logAndCrash fonksiyonu ise özel bir fonksiyon ve process uncaughtException tarafından kullanmak için yazdım. Burada farkettiyseniz hatayı logladıktan sonra tekrar throw ediyoruz. Bu node process'inin kapanmasına neden olacaktır. Bu konuya daha ayrıntılı ileride değineceğim.
logger'ın log fonksiyonunu override (üzerine yazma, ezme) ederek yararlı olacağını düşündüğüm errorMeta'yı error durumunda meta olarak ekliyorum.
Kullandığım transportlar, genel durumlar için Console, hata durumumları için File ve Redis. Loglama olduktan sonra redis'e girip bakarsanız winston adında bir list bulacaksınız.
Şimdi redisAdapter'da bir fonksiyonu değiştireceğiz. Redis'ten ilgili room'u bulamadığında bir Error throw ediyoruz:
Not: Promise kullanarak asenkron hataların yakalanmasını kolaylaştırabiliriz.
redisAdapter.js:
1...
2module.exports.getRoomById = function (roomId) {
3 var key = ROOMS + ':' + roomId;
4 return hgetall(key).then(function (room) {
5 if(!room) {
6 throw new Error('Room id not found:' + roomId);
7 }
8
9 return unflatten(room);
10 });
11};
12...
Burada da promise'deki hatayı catch ile yakalayıp next(..) ile exception handler'a gönderiyoruz.
routes/index.js:
1...
2router.get('/room/:id', securePage, function (req, res, next) {
3 var roomId = req.params.id;
4 roomAdapter.getRoomById(roomId).then(function (room) {
5 req.session.room = room;
6
7 res.render('room', {
8 user: JSON.stringify(req.user),
9 room: JSON.stringify(room),
10 socket_host: config.socket_host
11 });
12 }).catch(function (err) {
13 next(err);
14 }).done();
15});
16...
Express dökümantasyonundan: "If the current middleware does not end the request-response cycle, it must call next() to pass control to the next middleware, otherwise the request will be left hanging."
Express'te ya request sonlanmalı ya da sonraki middleware için next() çağrılmalıdır. Böylece request-response döngüsü bitirilir.
app.js:
1...
2var logger = require('src/lib/logging');
3...
4app.use(logger.loggerMiddleware);
5app.use(logger.exceptionMiddleware);
6process.on('uncaughtException', logger.logAndCrash);
7...
Şimdi gelelim logAndCrash'e. Node.js'in tek thread üzerinde çalışan bir uygulama olduğuna daha önceden değinmiştik. Asenkron yapısı nedeniyle de klasik ASP.NET, Java gibi web uygulamalarındaki gibi kullanıcıyı unhandled hata durumunda bir sayfaya yönlendirip hata oluştu diyemiyoruz (mesela Application_Error ile yapılabiliyor).
Burada yapılabilecek en doğru seçenek, ne yazıkki programı patlamasına izin vermektir. ASP.NET gibi web uygulamalarında her request farklı bir thread'de çalıştığından uygulamanın kalanı process durmadan devam edebilir ama node.js için aynı şeyi söyleyemeyiz.
Bu ve bunun gibi nedenlerden (unhandled hataların programın çalışmasını bozabilmesi, yanlış sonuçlar gibi) dolayı process'in çıkmasına izin veriyoruz. Uygulamanın tekrar çalışması için Forever, PM2 gibi çözümleri kullanabilirsiniz.
Kaynaklar:
Sonuç
Hata yönetimi ve loglamayla ilgili epey mesafe katettik. Sonraki yazım ölçeklenebilir loglama üzerine olacak. Node.js scaled yapıdaki sistemlerde nasıl loglarız, bu logları nasıl toplarız ve değerlendiririz konusunda yazacağım.
- Part 1 - Debugging Node.js
- Part 2 - Node.js Hata Yönetimi ve Loglama