Lua函数耗时统计-c版

101 阅读3分钟

zhuanlan.zhihu.com/p/667275238
根据这篇改了一版Lua5.1版本的profiler库。 做了一些内容:
1.添加了排序

2.key从函数地址改为函数名+文件名+行数,因为遇到闭包时会出现大量不同函数地址相同函数的情况,不方便查看。

3.哈希表改为khash,性能上没什么差别。

#include <stdio.h>
#include <string.h>
#include <assert.h>
#include <stdlib.h>
#include <stdint.h>

#include <lua.h>
#include <lauxlib.h>
#include <sys/time.h>
#include "khash.h"

static inline uint64_t gettime() {
    struct timeval tv;
    gettimeofday(&tv, NULL);
    uint64_t time = tv.tv_sec * 1000000 + tv.tv_usec;
    return time;
}

static inline double getsec(uint64_t t) {
    return (double) t / (1000000.0);
}

typedef struct {
    int call_count;
    uint64_t total_time;
    char* key;
} profile_record;

struct record_node{
    profile_record* data;
    struct record_node* next;
};

struct call_item {
    const char* name;
    const char* source;
    int line;
    uint64_t call_time;
    uint64_t pre_cost;
    uint64_t fun_ptr;
    struct call_item* next;
};

static struct call_item* stack_head = NULL;
KHASH_MAP_INIT_STR(map_str_record,profile_record*)
KHASH_MAP_INIT_INT64(map_int_str,char*)
khash_t(map_str_record) *recordMap = NULL;
static char maxKey[1024];

static inline void push_call(struct call_item* item) {
    item->next = stack_head;
    stack_head = item;
}

static inline struct call_item* pop_call() {
    struct call_item* item = stack_head;
    if(item == NULL){
        return NULL;
    }
    stack_head = item->next;
    return item;
}

static void profiler_hook(lua_State *L, lua_Debug *ar) {
    lua_getinfo(L, "Snlf", ar);
    if (ar->event == LUA_HOOKCALL) {
        struct call_item* item = (struct call_item*)malloc(sizeof(struct call_item));
        item->call_time = gettime();
        item->fun_ptr = lua_topointer(L, -1);
        item->name = ar->name ? ar->name : "?";
        item->source = ar->source ? ar->source : "?";
        item->line = ar->currentline;
        item->pre_cost = 0;
        push_call(item);
    }
    else if (ar->event == LUA_HOOKRET || ar->event == LUA_HOOKTAILRET) {
        struct call_item* item = NULL;
        item = pop_call();
        if (item == NULL ) {
            return;
        }
        
        int ret = 0;
        khiter_t iter = 0;
        uint64_t now = gettime();
        uint64_t cost = now - item->call_time;

        sprintf(maxKey, "%15s [%s:%d]", item->name,item->source,item->line);
        iter = kh_get(map_str_record, recordMap, maxKey);
        if(iter == kh_end(recordMap)){
            profile_record* record = (profile_record*)malloc(sizeof(profile_record));
            record->call_count = 1;
            record->total_time = cost - item->pre_cost;
            record->key = strdup(maxKey);
            iter = kh_put(map_str_record, recordMap, record->key, &ret);
            kh_value(recordMap, iter) = record;
        }else{
            profile_record* record = kh_value(recordMap, iter);
            record->call_count++;
            record->total_time += cost - item->pre_cost;
        }

        if(stack_head){
            stack_head->pre_cost += cost;
        }
        free(item);
    }
}

static int _start(lua_State *L) {
    if (stack_head) {
        printf("error: profiler already started\n");
        return 0;
    }

    recordMap = kh_init(map_str_record);
    if(recordMap == NULL){
        printf("error: recordMap create failed\n");
        return 0;
    }

    lua_sethook(L, profiler_hook, LUA_MASKCALL | LUA_MASKRET, 0);
    return 0;
}

static struct record_node* sort(uint64_t* totalTime)
{
    struct record_node* head = NULL;
    khiter_t iter = 0;
    for (iter = kh_begin(recordMap); iter != kh_end(recordMap); iter++) {
        if (!kh_exist(recordMap, iter)) {
            continue;
        }
        
        struct record_node* node = (struct record_node*)malloc(sizeof(struct record_node));
        node->data = kh_val(recordMap, iter);
        node->next = NULL;
        *totalTime += node->data->total_time;
        
        //从大到小插入
        if(head){
            struct record_node** curNodeRef = &head;
            struct record_node* lastNode = NULL;
            while(*curNodeRef){
                lastNode = *curNodeRef;
                if(node->data->total_time > (*curNodeRef)->data->total_time){
                    node->next = *curNodeRef;
                    *curNodeRef = node;
                    node = NULL;
                    break;
                }
                curNodeRef = &((*curNodeRef)->next);
            }
            if(node){
                lastNode->next = node;
            }
        }else{
            head = node;
        }
    }
    return head;
}

static int _stop(lua_State *L) {
    if (!stack_head) {
        printf("error: profiler not started\n");
        return 0;
    }
    lua_sethook(L, NULL, 0, 0);
    int nargs = lua_gettop(L);
    double ignore=0;
    if(nargs == 1){
        ignore = lua_tonumber(L,1);
    }
    
    khiter_t iter = 0;
    uint64_t totalTime = 0;
    struct record_node* curNode = sort(&totalTime);
    struct record_node* freeNode = NULL;
    profile_record* record = NULL;
    
    printf("profiler >>>>>>>>>>>>>>>>>>>> total time is %f  ignore < %lf\n\n", getsec(totalTime),ignore);
    printf("%-13s %-6s %15s \t\t\t%s\n","totaltime","percent","callcount","source");

    double percent = 0;
    while(curNode){
        record = curNode->data;
        if(record){
            percent = record->total_time*100.0/totalTime;
            if(percent > ignore){
                printf("%-13f %6.2f%% %15d \t\t%s\n", getsec(record->total_time),percent,record->call_count, record->key);
            }
            free(record->key);
            free(record);
        }
        freeNode = curNode;
        curNode = curNode->next;
        free(freeNode);
    }

    printf("profiler <<<<<<<<<<<<<<<<<<<<\n\n");
    fflush(stdout);
    
    kh_destroy(map_str_record, recordMap);

    struct call_item* curItem = stack_head;
    struct call_item* freeItem = NULL;
    while (curItem) {
        freeItem = curItem;
        curItem = curItem->next;
        free(freeItem);
    }
    stack_head = NULL;
    return 0;
}


int luaopen_profiler(lua_State *L) {
    luaL_Reg l[] = {
        {"start", _start},
        {"stop", _stop},
        {NULL, NULL},
    };
    luaL_register(L, "cprofiler", l);
    return 1;
}