整合Sentry和NodeJS实现分布式日志收集

Posted on 2014-12-26   |   In nodejs   |   
内容包括如何利用raven-node模块，完成nodejs服务与开源日志框架Sentry的对接，实现分布式日志收集，附Http接口的性能测试，不涉及Sentry的使用。

一、什么是Sentry？

一个基于Djongo的日志收集系统。具备收集日志（对于分布式环境下，日志分布在各台服务器上）、日志统计（统计次数最多的异常，往往这就是系统的隐患所在）、监控告警（出现异常或者异常积累到一定数量以短信或者邮件的形式告警）、以及以上功能的可视化界面。

目前我们部署公网sentry是6.4.4，
http://sentry.funshion.com/dev-web-ads/hermes/
支持的raven-node是0.7.2
https://github.com/getsentry/raven-node

二、NodeJS接入Sentry

在package.json中增加dependencies：”raven”: “0.7.2”

调用方式：

1
2
var raven = require(‘raven’);
var client = new raven.Client(‘http://32位:32位@sentryHost');

2.1 raven-node两种使用方式

  • 2.1.1 全局拦截与实现

调用：

1
client.patchGlobal();

源码如下，拦截所有uncaughtException。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
module.exports.patchGlobal = function patchGlobal(client, cb) {
    // handle when the first argument is the callback, with no client specified
    if(typeof client === 'function') {
        cb = client;
        client = new Client();
    // first argument is a string DSN
    } else if(typeof client === 'string') {
        client = new Client(client);
    }
    // at the end, if we still don't have a Client, let's make one!
    !(client instanceof Client) && (client = new Client());
    process.on('uncaughtException', function(err) {
        if(cb) {  // bind event listeners only if a callback was supplied
            client.once('logged', function() {
                cb(true, err);
            });
            client.once('error', function() {
                cb(false, err);
            });
        }
        client.captureError(err, function(result) {
            node_util.log('uncaughtException: '+client.getIdent(result));
        });
    });
};

测试下：

1
2
3
4
5
6
7
8
9
10
11
12
var raven = require("raven")
  var testRaven = function(){
    var client = new raven.Client('http://a374661ff0374e488...略');
    client.patchGlobal();
    try {
      throw new Error("test throw error");
    }catch(err){
      throw new Error("i'm caught error and throw myself again!")
    }
    //client.captureError('test captureMessage');
  }

在sentry上显示如下：
会显示function名，Error message，错误出现次数等
setry-test-item
点进详情，看到程序调用栈：
sentry-aggregation

  • 2.1.2 手动调用
1
2
3
4
// record a simple message
client.captureMessage('hello world!')
// capture an exception
client.captureError(new Error('Uh oh!!'));

2.2 raven-node推荐使用方式

统一使用第二种:
（1）对于uncaughtException使用下图方式输出到sentry：

1
2
3
4
5
process.on('uncaughtException', function(err) {
    ravenClient.captureError(err)
    //console.log("uncaughtException:" + err.stack);
    return false;
  });

（2）对于catchException或者业务错误，重写log的实现，完成可配置哪个log类型输出到sentry。

2.3 raven-node容灾考虑

看完怎么导入使用后，如果把它丢到生产环境，我想到的，还需要考虑的问题有：

（1）日志发送应该是纯异步的，不影响业务。
（2）发日志是调用tcp还是udp还是http接口。
（3）超时重发机制。
（4）sentry挂了怎么处理。
（5）sentry忙不过来怎么处理。
等等。

  • 2.3.1 raven-node支持的协议

要回答这些问题，看下sentry的transport.js。

1
2
3
4
module.exports.http = new HTTPTransport();
module.exports.https = new HTTPSTransport();
module.exports.udp = new UDPTransport();
module.exports.Transport = Transport;

支持三种方式，根据SENTRY创建项目的设置来实现，体现在SENTRY_DNS的host里。
因为我们都是对内网服务器日志的监控，一般使用http。

  • 2.3.2 raven-node中http协议实现-send函数
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
HTTPTransport.prototype.send = function(client, message, headers, ident) {
    var options = {
        hostname: client.dsn.host,
        path: client.dsn.path + 'api/store/',
        headers: headers,
        method: 'POST',
        port: client.dsn.port || this.defaultPort
    }, req = this.transport.request(options, function(res){
        res.setEncoding('utf8');
        if(res.statusCode >= 200 && res.statusCode < 300) {
            client.emit('logged', ident);
        } else {
            var reason = res.headers['x-sentry-error'];
            var e = new Error('HTTP Error (' + res.statusCode + '): ' + reason);
            e.response = res;
            e.statusCode = res.statusCode;
            e.reason = reason;
            e.sendMessage = message;
            e.requestHeaders = headers;
            e.ident = ident;
            client.emit('error', e);
        }
        // force the socket to drain
        var noop = function(){};
        res.on('data', noop);
        res.on('end', noop);
    });
    req.on('error', function(e){
        client.emit('error', e);
    });
    req.end(message);
};

代码很简短，post msg到{SENTRY_DSN}.host/dsn.path/api/store/，而且
（1）没有失败重试
（2）发送失败（resp状态码不是200或者req调用的error），发送事件到client.emit(‘error’)，再看下client对error事件的处理：none。

1
this.on('error', function(e) {});  // noop

三、小结与优化

3.1 疑问解答

回答下前面对sentry和raven-node的疑问：

  • （1）日志发送应该是纯异步的，不影响业务。
    raven-node send日志后是异步回调，但是调用发送日志api是同步的。
    （因为nodejs是单进程单线程，io异步基本已满足需求，如需优化，可以考虑对整个log模块独立进程，增加重试，发送流量控制等等，但是进程间内存拷贝开销会很大，nodejs的优劣还是很明显的，具体看应用场景）。
  • （2）发日志是调用tcp还是udp还是http接口。
    内网服务日志监控推荐http/udp。
  • （3）超时重发机制。
    无retry机制
  • （4）sentry挂了怎么处理。
  • （5）sentry忙不过来怎么处理。
    （sentry接受到的请求不是实时处理，接受请求通过队列实现。性能测试可参考：
    http://blog.csdn.net/largetalk/article/details/8640854）
    sentry挂了或者忙不过来，client会接收到error，但是不会输出任何异常。
  • （6）raven-node 连接是否会复用，大量日志需要输出的时候，io和句柄占用都会影响到业务处理，是否需要过载保护？
    参考3.2

3.2 优化与使用建议

针对上面的rave-node可能存在的问题，给出以下优化建议

3.2.1 规范哪些日志需要输出到sentry

  • 新增monitor logger类型，专用于输出到sentry
  • 必须error级别以上输出到sentry
  • error包括uncaughtException，业务异常，外部依赖服务异常，内部异常。（也可以增加服务正常启动的信息给sentry）

3.2.2 raven-node优化

上面提到的潜在问题总结为

  • 日志过多导致内存，句柄等资源占用过多的情况。
  • sentry异常，发送日志堆积，与日志过多情况相似。
  • 目前与sentry交互的异常日志没有输出（有优点也有缺点）。

建议

针对上面前两个问题，对raven-node封装或者扩展，支持固定大小的预发送队列。对外部依赖服务的异常进行隔离。

针对第三个问题，异常分为初始化和正常交互过程中两种情况

可以修改raven-node的client的prototype，支持异常输出日志。

或者常规解决方法：

正常交互过程中的异常：可以检测预发送队列的内容进行处理（如超过一定时间/次数，队列内容没有变更视为timeout异常），输出error日志。

初始化异常：因为封装raven-node后，client是复用的，仅当第一次初始化后，进行check，发送一个message：xxx服务启动。

四、性能测试

因sentry公网只开了Http的接口，对公网测试的Http接口性能测试如下：

环境：
本机(Mac os x 10.11)，双核四线程，node 0.8，raven-node 0.7.2

tps监测方式：统计raven-node client：response中end事件的输出时间

测试数据：

4个cluster
4000条300byte消息，
560ms发送完毕
4000条消息，总耗时约5.3s
tps大概765/s

1个cluster
4000条300byte消息，
900ms发送完毕
4000条消息，总耗时约11s
tps大概365/s

测试是否对项目有连接数的限制：
200个cluster
20条300byte消息
sentry的web管理界面卡顿，raven-node client返回正常

后续追加了不同cluster的性能表现：

总消息数为4000条，每条300byte
cluster个数-tps
4-765
8-1256
12-1430
16-1752
20-1690
32-1320
注：多个cluster未做类似Barrier的实现（即cluster发起请求非同一起点）会有误差。

结论：
sentry内部利用redis实现任务队列，测试机的tps在1800左右，预估还有较大提升，受限于测试机。如果使用http，极端情况下对client有压力，如果使用udp接口，问题不大，不影响client。另外，sentry连接数没有限制，连接管理表现一般。

参考：
Raven-node github：https://github.com/getsentry/raven-node
Getsentry官网：https://www.getsentry.com/docs/
使用开源软件sentry来收集日志：http://luxuryzh.iteye.com/blog/1980364
关于Sentry：http://blog.csdn.net/largetalk/article/details/8640854

（转载本站文章请注明作者和出处 Vernon Zheng(郑雪峰) – vernonzheng.com ，请勿用于任何商业用途）

#nodejs #sentry #监控 #性能测试
NodeJS实战经验总结
Coffeescript极简教程