# 调用链性能追踪

# 中间件性能计算

Daruk 会自动记录每个中间件的耗时，以及每个请求的中间件访问链路

你可以在 access 日志中将看到如下信息

{"requestId":"4876bd97-d098-4380-abcf-6a72f42da059","msg":"{\"daruk-logger\":1.196143,\"koa-handle-error\":0.236985,\"koa-x-request-id\":2.087368,\"asyncStore\":0.482164,\"koa-favicon\":0.198605,\"koa-bodyparser\":2.517215,\"koa-test-mid\":2.361615,\"router:/hello\":3.806353,\"sum\":12.886448}"}

requestId 为这次请求的 id，msg 信息为经过的中间件及耗时,通过记录耗时与方法追踪，我们可以直观的知道慢请求耗时在哪个中间件中。

# Daruk-monitor-middleware

Daruk 支持通过 v8-profiler 对 Node.js 进程进行分析。这个功能目前是通过中间件的形式支持的：https://github.com/darukjs/daruk-monitor-middleware

GET /monitor/profiler?period=2000

统计当前机器所有的 cpu 的性能情况以及内存的用量

参数 period：可以指定需要多少秒内的机器 cpu 性能默认 2000ms

结果：

{
    "cpu": {
        "device": {
            "userPercent": "0.18",
            "sysPercent": "0.11",
            "idlePercent": "0.70"
        },
        "process": {
            "elapTimeMS": 2003.953394,
            "elapUsageMS": 0.882,
            "cpuPercent": "0.0",
            "period": 2000
        }
    },
    "memory": {
        "rss": "43.16",
        "heapTotal": "51.62",
        "heapUsed": "45.38",
        "external": "0.08"
    }
}

GET /monitor/profiler/function?period=2000

统计某个时间段内的 function 执行耗时

参数 period：可以指定需要多少秒内的方法执行耗时默认 2000ms

结果(仅截取部分): 格式为执行时间 - 方法名 - 位置- 行号

(root)(101.1ms 100%)
[33m├── [0m[33m_tickCallback[0m (1.2ms 1.22%)(internal/process/next_tick.js 41)
[33m│   [0m[33m└── [0m[33mrunMicrotasks[0m (1.2ms 100.00%)
[33m│   [0m    [33m└── [0m[33mbodyParser[0m (1.2ms 100.00%)(/Daruk/node_modules/koa-bodyparser/index.js 72)
[33m│   [0m        [33m└── [0m[33mdispatch[0m (1.2ms 100.00%)(/Daruk/node_modules/koa/node_modules/koa-compose/index.js 35)
[33m│   [0m            [33m└── [0m[33manonymous[0m (1.2ms 100.00%)(/Daruk/src/index.ts 217)
[33m│   [0m

GET /monitor/profiler/mem

获取内存快照，下载当前 Node.js 进程的内存快照，然后通过 chrome 的 Profiler 进行分析

GET /monitor/profiler/mem-analytics

如果你不想通过上述路由下载快照手动分析，你可以通过该路由直接获取分析结果

结果:

{
    "heapMap": {},
    "leakPoint": [
        {
            "index": 27992,
            "size": 14347168,
            "id": "@55985"
        },
        {
            "index": 27993,
            "size": 13291464,
            "id": "@55987"
        },
        {
            "index": 148068,
            "size": 1658328,
            "id": "@296137"
        },
        {
            "index": 175630,
            "size": 1079872,
            "id": "@351261"
        },
        {
            "index": 224358,
            "size": 1079832,
            "id": "@448717"
        }
    ],
    "statistics": {
        "total": 49699126,
        "v8heap": 49609744,
        "native": 89382,
        "code": 2803392,
        "jsArrays": 1017696,
        "strings": 27068032,
        "system": 2052496
    },
    "rootIndex": 0,
    "aggregates": {
        "(system)": {
            "count": 106018,
            "distance": -5,
            "self": 5318360,
            "maxRet": 8091728,
            "type": "hidden",
            "name": null,
            "idxs": []
        },
        "(string)": {
            "count": 54471,
            "distance": 2,
            "self": 26389512,
            "maxRet": 26389512,
            "type": "string",
            "name": null,
            "idxs": []
        },
        "(array)": {
            "count": 46685,
            "distance": 2,
            "self": 8706440,
            "maxRet": 10222256,
            "type": "array",
            "name": null,
            "idxs": []
        },
        "(number)": {
            "count": 132,
            "distance": 2,
            "self": 2112,
            "maxRet": 2112,
            "type": "number",
            "name": null,
            "idxs": []
        },
        "(symbol)": {
            "count": 159,
            "distance": 3,
            "self": 5088,
            "maxRet": 5752,
            "type": "symbol",
            "name": null,
            "idxs": []
        },
        "(compiled code)": {
            "count": 18662,
            "distance": 3,
            "self": 2803392,
            "maxRet": 29539184,
            "type": "code",
            "name": null,
            "idxs": []
        },
        "(closure)": {
            "count": 21583,
            "distance": 2,
            "self": 1357232,
            "maxRet": 13263436,
            "type": "closure",
            "name": null,
            "idxs": []
        },
        "Object": {
            "count": 17200,
            "distance": 2,
            "self": 1016888,
            "maxRet": 8980248,
            "type": "object",
            "name": "Object",
            "idxs": []
        },
        "system / Context": {
            "count": 5333,
            "distance": 3,
            "self": 407400,
            "maxRet": 7163126,
            "type": "object",
            "name": "system / Context",
            "idxs": []
        },
        "Monitor": {
            "count": 1,
            "distance": 8,
            "self": 184,
            "maxRet": 91400,
            "type": "object",
            "name": "Monitor",
            "idxs": []
        },
        "global": {
            "count": 2,
            "distance": 1,
            "self": 72,
            "maxRet": 47648758,
            "type": "object",
            "name": "global",
            "idxs": []
        },
        "daruk": {
            "count": 1,
            "distance": 7,
            "self": 272,
            "maxRet": 20440,
            "type": "object",
            "name": "daruk",
            "idxs": []
        }
        // ...省略等

部署