V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
爱意满满的作品展示区。
1heart
V2EX  ›  分享创造

Koa 请求日志打点工具(上篇)

  •  
  •   1heart · 2016-12-15 12:45:27 +08:00 · 2445 次点击
    这是一个创建于 2908 天前的主题,其中的信息可能已经有所发展或是发生改变。

    前一段时间开始搞优化后端 API 性能的事,发现根本无从下手, Kibana 中虽然有记一些简陋且零散的日志,但也瞅不出啥眉目来。总结了下是日志太少了,所以决定先搞搞日志的事,目标是记录 API 请求相关的日志,找出哪个接口慢,最好具体到哪个函数慢。

    记日志必然要涉及日志打点,怎么做日志打点是个问题。如果直接在代码中插入日志打点代码不仅侵入性强而且工作量大,也不够灵活,于是考虑如何做智能的自动打点。我们石墨后端使用的 bay 框架(基于 Koa@1 二次开发,基本上你可以认为就是用的 Koa ), controller 里用了大量的 yield ,所以考虑是不是可以在 yield 表达式前后打点,调研了下觉得可以用 esprima 和 escodegen 做。

    奋战几天, koa-yield-breakpoint 诞生了。

    koa-yield-breakpoint

    koa-yield-breakpoint 就是一个在 controllers 或者 routes 里的 yield 表达式前后打点的工具,不用插入一行日志打点代码,只需要在引入的时候配置一下,可以记录每个请求到来时 yield 表达式前后的现场,如:

    1 、 yield 表达式所在的行列号( filename ) 2 、 yield 表达式是执行的第几步( step ) 3 、 yield 表达式字符串形式( fn ) 4 、执行 yield 表达式所花费的时间( take ) 5 、执行 yield 表达式的结果( result ) 6 、 yield 表达式当时的现场( this ),通过 this 你也可以添加自定义字段

    原理:

    1 、重载 Module.prototype.-compile ,相当于 hack 了 require ,如果发现是 require 了配置里指定的的文件,则进行下一步,否则返回原始代码内容,相关源代码如下:

    shimmer.wrap(Module.prototype, '_compile', function (__compile) {
      return function koaBreakpointCompile(content, filename) {
        if (!_.includes(filenames, filename)) {
          return __compile.call(this, content, filename);
        }
        ...
      };
    });
    

    2 、用 esprima 解析代码,生成 AST 。如:

    'use strict';
    
    const Mongolass = require('mongolass');
    const mongolass = new Mongolass();
    mongolass.connect('mongodb://localhost:27017/test');
    
    exports.getUsers = function* getUsers() {
      yield mongolass.model('users').create({
        name: 'xx',
        age: 18
      });
    
      const users = yield mongolass.model('users').find();
      this.body = users;
    };
    

    会生成如下 AST :

    Program {
      type: 'Program',
      body:
       [ Directive {
           type: 'ExpressionStatement',
           expression:
            Literal {
              type: 'Literal',
              value: 'use strict',
              raw: '\'use strict\'',
              loc: { start: { line: 1, column: 0 }, end: { line: 1, column: 12 } } },
           directive: 'use strict',
           loc: { start: { line: 1, column: 0 }, end: { line: 1, column: 13 } } },
         VariableDeclaration {
           type: 'VariableDeclaration',
           declarations:
            [ VariableDeclarator {
                type: 'VariableDeclarator',
                id:
                 Identifier {
                   type: 'Identifier',
                   name: 'Mongolass',
                   loc: { start: { line: 3, column: 6 }, end: { line: 3, column: 15 } } },
                init:
                 CallExpression {
                   type: 'CallExpression',
                   callee:
                    Identifier {
                      type: 'Identifier',
                      name: 'require',
                      loc: { start: { line: 3, column: 18 }, end: { line: 3, column: 25 } } },
                   arguments:
                    [ Literal {
                        type: 'Literal',
                        value: 'mongolass',
                        raw: '\'mongolass\'',
                        loc: { start: { line: 3, column: 26 }, end: { line: 3, column: 37 } } } ],
                   loc: { start: { line: 3, column: 18 }, end: { line: 3, column: 38 } } },
                loc: { start: { line: 3, column: 6 }, end: { line: 3, column: 38 } } } ],
           kind: 'const',
           loc: { start: { line: 3, column: 0 }, end: { line: 3, column: 39 } } },
         VariableDeclaration {
           type: 'VariableDeclaration',
           declarations:
            [ VariableDeclarator {
                type: 'VariableDeclarator',
                id:
                 Identifier {
                   type: 'Identifier',
                   name: 'mongolass',
                   loc: { start: { line: 4, column: 6 }, end: { line: 4, column: 15 } } },
                init:
                 NewExpression {
                   type: 'NewExpression',
                   callee:
                    Identifier {
                      type: 'Identifier',
                      name: 'Mongolass',
                      loc: { start: { line: 4, column: 22 }, end: { line: 4, column: 31 } } },
                   arguments: [],
                   loc: { start: { line: 4, column: 18 }, end: { line: 4, column: 33 } } },
                loc: { start: { line: 4, column: 6 }, end: { line: 4, column: 33 } } } ],
           kind: 'const',
           loc: { start: { line: 4, column: 0 }, end: { line: 4, column: 34 } } },
         ExpressionStatement {
           type: 'ExpressionStatement',
           expression:
            CallExpression {
              type: 'CallExpression',
              callee:
               StaticMemberExpression {
                 type: 'MemberExpression',
                 computed: false,
                 object:
                  Identifier {
                    type: 'Identifier',
                    name: 'mongolass',
                    loc: { start: { line: 5, column: 0 }, end: { line: 5, column: 9 } } },
                 property:
                  Identifier {
                    type: 'Identifier',
                    name: 'connect',
                    loc: { start: { line: 5, column: 10 }, end: { line: 5, column: 17 } } },
                 loc: { start: { line: 5, column: 0 }, end: { line: 5, column: 17 } } },
              arguments:
               [ Literal {
                   type: 'Literal',
                   value: 'mongodb://localhost:27017/test',
                   raw: '\'mongodb://localhost:27017/test\'',
                   loc: { start: { line: 5, column: 18 }, end: { line: 5, column: 50 } } } ],
              loc: { start: { line: 5, column: 0 }, end: { line: 5, column: 51 } } },
           loc: { start: { line: 5, column: 0 }, end: { line: 5, column: 52 } } },
         ExpressionStatement {
           type: 'ExpressionStatement',
           expression:
            AssignmentExpression {
              type: 'AssignmentExpression',
              operator: '=',
              left:
               StaticMemberExpression {
                 type: 'MemberExpression',
                 computed: false,
                 object:
                  Identifier {
                    type: 'Identifier',
                    name: 'exports',
                    loc: { start: { line: 7, column: 0 }, end: { line: 7, column: 7 } } },
                 property:
                  Identifier {
                    type: 'Identifier',
                    name: 'getUsers',
                    loc: { start: { line: 7, column: 8 }, end: { line: 7, column: 16 } } },
                 loc: { start: { line: 7, column: 0 }, end: { line: 7, column: 16 } } },
              right:
               FunctionExpression {
                 type: 'FunctionExpression',
                 id:
                  Identifier {
                    type: 'Identifier',
                    name: 'getUsers',
                    loc: { start: { line: 7, column: 29 }, end: { line: 7, column: 37 } } },
                 params: [],
                 body:
                  BlockStatement {
                    type: 'BlockStatement',
                    body:
                     [ ExpressionStatement {
                         type: 'ExpressionStatement',
                         expression:
                          YieldExpression {
                            type: 'YieldExpression',
                            argument:
                             CallExpression {
                               type: 'CallExpression',
                               callee:
                                StaticMemberExpression {
                                  type: 'MemberExpression',
                                  computed: false,
                                  object: [Object],
                                  property: [Object],
                                  loc: [Object] },
                               arguments: [ [Object] ],
                               loc: { start: [Object], end: [Object] } },
                            delegate: false,
                            loc: { start: { line: 8, column: 2 }, end: { line: 11, column: 4 } } },
                         loc: { start: { line: 8, column: 2 }, end: { line: 11, column: 5 } } },
                       VariableDeclaration {
                         type: 'VariableDeclaration',
                         declarations:
                          [ VariableDeclarator {
                              type: 'VariableDeclarator',
                              id: Identifier { type: 'Identifier', name: 'users', loc: [Object] },
                              init:
                               YieldExpression {
                                 type: 'YieldExpression',
                                 argument: [Object],
                                 delegate: false,
                                 loc: [Object] },
                              loc: { start: [Object], end: [Object] } } ],
                         kind: 'const',
                         loc:
                          { start: { line: 13, column: 2 },
                            end: { line: 13, column: 54 } } },
                       ExpressionStatement {
                         type: 'ExpressionStatement',
                         expression:
                          AssignmentExpression {
                            type: 'AssignmentExpression',
                            operator: '=',
                            left:
                             StaticMemberExpression {
                               type: 'MemberExpression',
                               computed: false,
                               object: ThisExpression { type: 'ThisExpression', loc: [Object] },
                               property: Identifier { type: 'Identifier', name: 'body', loc: [Object] },
                               loc: { start: [Object], end: [Object] } },
                            right:
                             Identifier {
                               type: 'Identifier',
                               name: 'users',
                               loc: { start: [Object], end: [Object] } },
                            loc:
                             { start: { line: 14, column: 2 },
                               end: { line: 14, column: 19 } } },
                         loc:
                          { start: { line: 14, column: 2 },
                            end: { line: 14, column: 20 } } } ],
                    loc: { start: { line: 7, column: 40 }, end: { line: 15, column: 1 } } },
                 generator: true,
                 expression: false,
                 loc: { start: { line: 7, column: 19 }, end: { line: 15, column: 1 } } },
              loc: { start: { line: 7, column: 0 }, end: { line: 15, column: 1 } } },
           loc: { start: { line: 7, column: 0 }, end: { line: 15, column: 2 } } } ],
      sourceType: 'script',
      loc: { start: { line: 1, column: 0 }, end: { line: 15, column: 2 } } }
    

    相关源代码如下:

    let parsedCodes;
    try {
      parsedCodes = esprima.parse(content, { loc: true });
    } catch (e) {
      console.error('cannot parse file: %s', filename);
      console.error(e.stack);
      process.exit(1);
    }
    

    3 、遍历找到 YieldExpression 节点,进行以下包装后生成 AST 替换掉原来的节点。

    global.logger(
      this,
      function*(){
        return YieldExpression
      },
      YieldExpressionString,
      filename
    );
    

    相关源代码如下:

    findYieldAndWrapLogger(parsedCodes);
    try {
      content = escodegen.generate(parsedCodes, {
        format: { indent: { style: '  ' } },
        sourceMap: filename,
        sourceMapWithCode: true
      });
    } catch (e) {
      console.error('cannot generate code for file: %s', filename);
      console.error(e.stack);
      process.exit(1);
    }
    debug('file %s regenerate codes:\n%s', filename, content.code);
    

    findYieldAndWrapLogger 作用就是遍历 AST 将 YieldExpression 替换成用日志函数包裹后新的 YieldExpression 的 AST 。

    <未完待续> ----敬请期待 Koa 请求日志打点工具(下篇)

    目前尚无回复
    关于   ·   帮助文档   ·   博客   ·   API   ·   FAQ   ·   实用小工具   ·   930 人在线   最高记录 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 28ms · UTC 20:01 · PVG 04:01 · LAX 12:01 · JFK 15:01
    Developed with CodeLauncher
    ♥ Do have faith in what you're doing.