Lua Profiler机制的源码解析

一. Lua Profiler介绍和使用

1. Lua Profiler介绍

官网:
http://luaprofiler.luaforge.net/
使用手册:
http://luaprofiler.luaforge.net/manual.html
source code:
https://github.com/luaforge/luaprofiler

2. Lua Profiler的使用

local function DoSomethingMore(x)
  x = x / 2
end

local function DoSomething(x)
  x = x + 1
  if x % 2 then DoSomethingMore(x) end
end

prf = require("profiler") -- 引入profiler模块
prf.start()  -- start
for outer=1,3 do
  for inner=1,2 do
    DoSomething(inner)
  end
end
prf.stop()  -- stop

二. 基础数据结构

1. clock_t

clock_t ==> unsigned long (8byte);

2. STACK_RECORD&sSTATE

struct lprofP_sSTATE {
   int stack_level;
   lprofS_STACK stack_top;
};

其中, stack_top是一个指针, 其指向栈顶的Stack_Record;

struct lprofS_sSTACK_RECORD {
    clock_t time_marker_function_local_time;
    clock_t time_marker_function_total_time;
    char *file_defined;
    char *function_name;
    char *source_code;        
    long line_defined;
    long current_line;
    float local_time;
    float total_time;
    lprofS_STACK_RECORD *next;
};

三. 操作

1. 创建Profiler:lprofP_init_core_profiler >> lprofM_init

/* opens the log file */
/* returns true if the file could be opened */
lprofP_STATE* lprofP_init_core_profiler(const char *_out_filename, int isto_printheader, float _function_call_time) {
  lprofP_STATE* S;
  char auxs[256];
  char *s;
  char *randstr;
  const char *out_filename;

  function_call_time = _function_call_time;
  out_filename = (_out_filename) ? (_out_filename):(OUT_FILENAME);
        
  /* the random string to build the logname is extracted */
  /* from 'tmpnam()' (the '/tmp/' part is deleted)     */
  randstr = tmpnam(NULL);
  for (s = strtok(randstr, "/\\"); s; s = strtok(NULL, "/\\")) {
    randstr = s;
  }

  if(randstr[strlen(randstr)-1]=='.')
    randstr[strlen(randstr)-1]='\0';

  sprintf(auxs, out_filename, randstr);
  outf = fopen(auxs, "a");  //open a file named auxs, appending mode
  if (!outf) {
    return 0;
  }

  if (isto_printheader) {
    output("stack_level\tfile_defined\tfunction_name\tline_defined\tcurrent_line\tlocal_time\ttotal_time\n");
  }

  /* initialize the 'function_meter' */
  S = lprofM_init();  //一个关键的函数, 初始化S指针, 让其指向sSTATE栈, 也就是功能上的Meter计时器
  if(!S) {
    fclose(outf);
    return 0;
  }
    
  return S;
}

我们接着往下看, Meter计时器的初始化lprofM_init函数

/* init stack */
lprofP_STATE* lprofM_init() {
  lprofP_STATE *S;
  S = (lprofP_STATE*)malloc(sizeof(lprofP_STATE));
  if(S) {
    S->stack_level = 0;
    S->stack_top = NULL;
    return S;
  } else return NULL;
}

M_init函数干的事很简单, 就是创建一个sSTATE,也就是创建了一个栈。

2. call序列:lprofP_callhookIN >> lprofM_enter_function

/* computes new stack and new timer */
void lprofP_callhookIN(lprofP_STATE* S, char *func_name, char *file, int linedefined, int currentline) {    
  S->stack_level++;
  lprofM_enter_function(S, file, func_name, linedefined, currentline);
}
/* the local time for the parent function is paused  */
/* and the local and total time markers are started */
void lprofM_enter_function(lprofP_STATE* S, char *file_defined, char *fcn_name, long linedefined, long currentline) {
  char* prev_name;
  char* cur_name;
  /* the flow has changed to another function: */
  /* pause the parent's function timer timer   */
  if (S->stack_top) {
    lprofM_pause_local_time(S);  //传入指向STATE的指针S, 对其STATE.stack_top所指向的frame的timer进行暂停操作
    prev_name = S->stack_top->function_name;  //把前一个函数的名字记下来
  } else prev_name = "top level";
  /* measure new function */
  lprofC_start_timer(&(newf.time_marker_function_local_time));  //开始新的timer
  lprofC_start_timer(&(newf.time_marker_function_total_time)); 
  newf.file_defined = file_defined;  //对新的frame做初始化
  if(fcn_name != NULL) {
    newf.function_name = fcn_name;  
  } else if(strcmp(file_defined, "=[C]") == 0) {
    cur_name = (char*)malloc(sizeof(char)*(strlen("called from ")+strlen(prev_name)+1));
    sprintf(cur_name, "called from %s", prev_name);  //prev_name是上一个frame中记录的函数名
    newf.function_name = cur_name;
  } else {
    cur_name = (char*)malloc(sizeof(char)*(strlen(file_defined)+12));
    sprintf(cur_name, "%s:%li", file_defined, linedefined);
    newf.function_name = cur_name;
  }    
  newf.line_defined = linedefined;
  newf.current_line = currentline;
  newf.local_time = 0.0;
  newf.total_time = 0.0;
  lprofS_push(&(S->stack_top), newf); //往STATE.stack_top所对应的stack中push进去一个新的record(一个记录, 等同于一个stack frame)
}

3. return序列: lprofP_callhookOUT >> lprofM_leave_function

/* pauses all timers to write a log line and computes the new stack */
/* returns if there is another function in the stack */
int lprofP_callhookOUT(lprofP_STATE* S) {

  S->stack_level--;
  /* 0: do not resume the parent function's timer yet... */
  info = lprofM_leave_function(S, 0);
  /* writing a log may take too long to be computed with the function's time ...*/
  lprofM_pause_total_time(S);
  info->local_time += function_call_time;
  info->total_time += function_call_time;
  
  char* source = info->file_defined;
  char* name = info->function_name;
  
// begin output...  
  output("%d\t%s\t%s\t%d\t%d\t%f\t%f\n", S->stack_level, source, name, 
     info->line_defined, info->current_line,
     info->local_time, info->total_time);
  // output finished!!!

  /* ... now it's ok to resume the timer */
  if (S->stack_level != 0) {
    lprofM_resume_function(S);
  }

  return 1;

}
lprofS_STACK_RECORD *lprofM_leave_function(lprofP_STATE* S, int isto_resume) {

  ASSERT(S->stack_top, "leave_function: stack_top null");
  leave_ret = lprofS_pop(&(S->stack_top));
  compute_local_time(&leave_ret);  //更新stack_record.local_time
  compute_total_time(&leave_ret);  //更新stack_record.total_time
  /* resume the timer for the parent function ? */
  if (isto_resume)
    lprofM_resume_local_time(S);
  return &leave_ret;
}

思考: 最关键的问题来了, 当我们准备好这些profilerInit, callHookIN, callHookOut函数后, 是如何被与target函数挂上钩的?

四. hook原理

1. profiler模块函数的定义

根据profiler module的注册代码, start函数和stop函数对应的是init和stop函数
static const luaL_reg prof_funcs[] = {
{ "pause", profiler_pause },
{ "resume", profiler_resume },
{ "start", profiler_init },
{ "stop", profiler_stop },
{ NULL, NULL }
};

1)init函数

static int profiler_init(lua_State *L) {
  lprofP_STATE* S;
  float function_call_time;
  lua_pop(L, 1);
  function_call_time = calcCallTime(L);
 //left out some code to set name of output file...
  lua_sethook(L, (lua_Hook)callhook, LUA_MASKCALL | LUA_MASKRET, 0);  //关键代码行

  lua_pushlightuserdata(L, &profstate_id);
  lua_pushlightuserdata(L, S);
  lua_settable(L, LUA_REGISTRYINDEX);

  /* use our own exit function instead */
  lua_getglobal(L, "os");
  lua_pushlightuserdata(L, &exit_id);
  lua_pushstring(L, "exit");
  lua_gettable(L, -3);
  lua_settable(L, LUA_REGISTRYINDEX);
  lua_pushstring(L, "exit");
  lua_pushcfunction(L, (lua_CFunction)exit_profiler);
  lua_settable(L, -3);
  return 1;
}

注意到这其中调用了lua_sethook函数。(下面马上要说到)

2)stop函数

static int profiler_stop(lua_State *L) {
  lprofP_STATE* S;
  lua_sethook(L, (lua_Hook)callhook, 0, 0); //关键代码行
  lua_pushlightuserdata(L, &profstate_id);
  lua_gettable(L, LUA_REGISTRYINDEX);
  if(!lua_isnil(L, -1)) {
    S = (lprofP_STATE*)lua_touserdata(L, -1);
    /* leave all functions under execution */
    while (lprofP_callhookOUT(S));
    lprofP_close_core_profiler(S);
    lua_pushlightuserdata(L, &profstate_id);
    lua_pushnil(L);
    lua_settable(L, LUA_REGISTRYINDEX);
    lua_pushboolean(L, 1);
  } else { lua_pushboolean(L, 0); }
  return 1;
}

2. 挂钩过程

1) lua_sethook函数(关键函数)

这个函数定义在了ldebug.c文件中, 是Lua语言debug相关功能的核心代码部分;

/*
** this function can be called asynchronous (e.g. during a signal)
*/
LUA_API int lua_sethook (lua_State *L, lua_Hook func, int mask, int count) {
  if (func == NULL || mask == 0) {  /* turn off hooks? */
    mask = 0;
    func = NULL;
  }
  L->hook = func;  // 最关键的一行代码, 把L->hook设置成了func
  L->basehookcount = count;
  resethookcount(L);
  L->hookmask = cast_byte(mask);
  return 1;
}

这个函数其实做的事比较简单, 就是把lua_State.hook设置成传入的callhook函数.
接下来一起看看callhook函数做了什么.

2) 被设置到L->hook中的callhook函数

static void callhook(lua_State *L, lua_Debug *ar) {
  int currentline;
  lua_Debug previous_ar;
  lprofP_STATE* S;  //STATE类型指针S
  lua_pushlightuserdata(L, &profstate_id);
  lua_gettable(L, LUA_REGISTRYINDEX);
  S = (lprofP_STATE*)lua_touserdata(L, -1);

  if (lua_getstack(L, 1, &previous_ar) == 0) {
    currentline = -1;
  } else {
    lua_getinfo(L, "l", &previous_ar);
    currentline = previous_ar.currentline;
  }
      
  lua_getinfo(L, "nS", ar);

  if (!ar->event) {  //关键代码部分:做事件的分发, 要么是call, 要么是return.
    /* entering a function */
    lprofP_callhookIN(S, (char *)ar->name,
              (char *)ar->source, ar->linedefined,
              currentline);
  }
  else { /* ar->event == "return" */
    lprofP_callhookOUT(S);
  }
}

那么留给我们的问题又来了, 这个lua_Debug类型的ar指针, 到底是何方神圣, 为什么!(ar->event)就是进入函数, 而else就是return回去呢?
lua_Debug类型定义如下, 其实就是一个存放了一些debug相关信息的数据结构, 其中有一个属性叫event。

typedef struct lua_Debug {
  int event;  //根据上下文推荐, 0是call, 其他是return;
  const char *name;           /* (n) */
  const char *namewhat;       /* (n) */
  const char *what;           /* (S) */
  const char *source;         /* (S) */
  int currentline;            /* (l) */
  int nups;                   /* (u) number of upvalues */
  int linedefined;            /* (S) */
  int lastlinedefined;        /* (S) */
  char short_src[LUA_IDSIZE]; /* (S) */
  /* private part */
  other fields
} lua_Debug;

event的数值含义在lua.h中可以找到

/*
** Event codes, 来自lua.h文件
*/
#define LUA_HOOKCALL    0
#define LUA_HOOKRET    1
#define LUA_HOOKLINE    2
#define LUA_HOOKCOUNT    3
#define LUA_HOOKTAILRET 4

稍微总结一下, 目前为止, 我们知道了lua_Debug.event = {0, 1, 2, ...} (见上面的代码段).

我们可以利用ldebug.c文件中的lua_sethook函数传入一个callhook函数作为事件的分发器(被挂在L->hook字段上). callhook函数可以根据lua_Debug.event的值, 来判断要呼叫callhookIN 还是 callhookOUT函数.

所以说, 在导入profiler模块后, 当执行了profiler.start()函数的时候,
该函数的代码lua_sethook(lua_State *L = L, lua_Hook func = (lua_Hook)callhook, int mask = LUA_MASKCALL | LUA_MASKRET, int count = 0) 运行了, 就把callhook函数这个事件分发器给装配到了L上(有一行代码写lua_State.hook = callhook)

所以我们接下来需要关心, 在底层的LuaVM中,L->hook函数什么时候被调用的呢?(底层调用L->hook的机制)

3. LVM调用hook的机制

1)luaV_execute

作为LVM的虚拟机主要函数, 其的结构其实非常简单,就是一个很长很长的switch。

switch(opcode):
  case OP_01:
      xxx;
      break;
  case OP_02:
      xxx;
      break;
  (...etc...)

其中,OP_CALL(call操作)的代码如下

case OP_CALL: {
        int b = GETARG_B(i);
        int nresults = GETARG_C(i) - 1;
        if (b != 0) L->top = ra+b;  /* else previous instruction set top */
        L->savedpc = pc;
        switch (luaD_precall(L, ra, nresults)) {  //关键行:此处调用precall函数
          case PCRLUA: {
            nexeccalls++;
            goto reentry;  /* restart luaV_execute over new Lua function */
          }
          case PCRC: {
            /* it was a C function (`precall' called it); adjust results */
            if (nresults >= 0) L->top = L->ci->top;
            base = L->base;
            continue;
          }
          default: {
            return;  /* yield */
          }
        }
      }

原来在lvm.c中的void luaV_execute(lua_State *L)这个虚拟机的执行函数中, 对OP_CALL(call操作)的定义中, 就有luaD_precall的存在.

2) luaD_precall (ldo.c)

int luaD_precall (lua_State *L, StkId func, int nresults) {
... //省略一些代码
if (L->hookmask & LUA_MASKCALL) {
      L->savedpc++;  /* hooks assume 'pc' is already incremented */
      luaD_callhook(L, LUA_HOOKCALL, -1);  //只要看到有这行代码就行了
      L->savedpc--;  /* correct 'pc' */
    }
... //省略一些代码
}

继续往下看这个luaD_callhook函数, 这里, 我们传入的参数是(L, 0, -1)

void luaD_callhook (lua_State *L, int event, int line) {
  lua_Hook hook = L->hook;  //关键行!!!hook就是我们最开始所赋值的callhook事件分发函数
  if (hook && L->allowhook) {
    ptrdiff_t top = savestack(L, L->top);
    ptrdiff_t ci_top = savestack(L, L->ci->top);
    lua_Debug ar;
    ar.event = event;  //关键行!!!把0赋值给ar.event
    ar.currentline = line;
    if (event == LUA_HOOKTAILRET)
      ar.i_ci = 0;  /* tail call; no debug information about it */
    else
      ar.i_ci = cast_int(L->ci - L->base_ci);
    luaD_checkstack(L, LUA_MINSTACK);  /* ensure minimum stack size */
    L->ci->top = L->top + LUA_MINSTACK;
    lua_assert(L->ci->top <= L->stack_last);
    L->allowhook = 0;  /* cannot call hooks inside a hook */
    lua_unlock(L);
    (*hook)(L, &ar);  //关键代码!!! 调用hook函数, 传入L和&ar作为参数.
    lua_lock(L);
    lua_assert(!L->allowhook);
    L->allowhook = 1;
    L->ci->top = restorestack(L, ci_top);
    L->top = restorestack(L, top);
  }
}

至此, LVM中L->hook被调用的过程我们也看明白了, 其原本就存在于虚拟机主函数luaV_execute中.
这个逻辑链是luaV_execute --> OP_CALL --> luaD_precall (属于ldo.c文件) --> luaD_callhook --> (*hook)(L, &ar)

END.

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 196,099评论 5 462
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 82,473评论 2 373
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 143,229评论 0 325
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 52,570评论 1 267
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 61,427评论 5 358
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 46,335评论 1 273
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 36,737评论 3 386
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 35,392评论 0 254
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 39,693评论 1 294
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 34,730评论 2 312
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 36,512评论 1 326
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 32,349评论 3 314
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 37,750评论 3 299
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,017评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 30,290评论 1 251
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 41,706评论 2 342
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 40,904评论 2 335

推荐阅读更多精彩内容