调用链性能追踪

中间件性能计算

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

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

  1. {"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

  1. GET /monitor/profiler?period=2000

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

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

结果:

  1. {
  2. "cpu": {
  3. "device": {
  4. "userPercent": "0.18",
  5. "sysPercent": "0.11",
  6. "idlePercent": "0.70"
  7. },
  8. "process": {
  9. "elapTimeMS": 2003.953394,
  10. "elapUsageMS": 0.882,
  11. "cpuPercent": "0.0",
  12. "period": 2000
  13. }
  14. },
  15. "memory": {
  16. "rss": "43.16",
  17. "heapTotal": "51.62",
  18. "heapUsed": "45.38",
  19. "external": "0.08"
  20. }
  21. }
  1. GET /monitor/profiler/function?period=2000

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

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

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

  1. (root)(101.1ms 100%)
  2. ├── _tickCallback (1.2ms 1.22%)(internal/process/next_tick.js 41)
  3.  └── runMicrotasks (1.2ms 100.00%)
  4.   └── bodyParser (1.2ms 100.00%)(/Daruk/node_modules/koa-bodyparser/index.js 72)
  5.   └── dispatch (1.2ms 100.00%)(/Daruk/node_modules/koa/node_modules/koa-compose/index.js 35)
  6.   └── anonymous (1.2ms 100.00%)(/Daruk/src/index.ts 217)
  7.   
  1. GET /monitor/profiler/mem

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

  1. GET /monitor/profiler/mem-analytics

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

结果:

  1. {
  2. "heapMap": {},
  3. "leakPoint": [
  4. {
  5. "index": 27992,
  6. "size": 14347168,
  7. "id": "@55985"
  8. },
  9. {
  10. "index": 27993,
  11. "size": 13291464,
  12. "id": "@55987"
  13. },
  14. {
  15. "index": 148068,
  16. "size": 1658328,
  17. "id": "@296137"
  18. },
  19. {
  20. "index": 175630,
  21. "size": 1079872,
  22. "id": "@351261"
  23. },
  24. {
  25. "index": 224358,
  26. "size": 1079832,
  27. "id": "@448717"
  28. }
  29. ],
  30. "statistics": {
  31. "total": 49699126,
  32. "v8heap": 49609744,
  33. "native": 89382,
  34. "code": 2803392,
  35. "jsArrays": 1017696,
  36. "strings": 27068032,
  37. "system": 2052496
  38. },
  39. "rootIndex": 0,
  40. "aggregates": {
  41. "(system)": {
  42. "count": 106018,
  43. "distance": -5,
  44. "self": 5318360,
  45. "maxRet": 8091728,
  46. "type": "hidden",
  47. "name": null,
  48. "idxs": []
  49. },
  50. "(string)": {
  51. "count": 54471,
  52. "distance": 2,
  53. "self": 26389512,
  54. "maxRet": 26389512,
  55. "type": "string",
  56. "name": null,
  57. "idxs": []
  58. },
  59. "(array)": {
  60. "count": 46685,
  61. "distance": 2,
  62. "self": 8706440,
  63. "maxRet": 10222256,
  64. "type": "array",
  65. "name": null,
  66. "idxs": []
  67. },
  68. "(number)": {
  69. "count": 132,
  70. "distance": 2,
  71. "self": 2112,
  72. "maxRet": 2112,
  73. "type": "number",
  74. "name": null,
  75. "idxs": []
  76. },
  77. "(symbol)": {
  78. "count": 159,
  79. "distance": 3,
  80. "self": 5088,
  81. "maxRet": 5752,
  82. "type": "symbol",
  83. "name": null,
  84. "idxs": []
  85. },
  86. "(compiled code)": {
  87. "count": 18662,
  88. "distance": 3,
  89. "self": 2803392,
  90. "maxRet": 29539184,
  91. "type": "code",
  92. "name": null,
  93. "idxs": []
  94. },
  95. "(closure)": {
  96. "count": 21583,
  97. "distance": 2,
  98. "self": 1357232,
  99. "maxRet": 13263436,
  100. "type": "closure",
  101. "name": null,
  102. "idxs": []
  103. },
  104. "Object": {
  105. "count": 17200,
  106. "distance": 2,
  107. "self": 1016888,
  108. "maxRet": 8980248,
  109. "type": "object",
  110. "name": "Object",
  111. "idxs": []
  112. },
  113. "system / Context": {
  114. "count": 5333,
  115. "distance": 3,
  116. "self": 407400,
  117. "maxRet": 7163126,
  118. "type": "object",
  119. "name": "system / Context",
  120. "idxs": []
  121. },
  122. "Monitor": {
  123. "count": 1,
  124. "distance": 8,
  125. "self": 184,
  126. "maxRet": 91400,
  127. "type": "object",
  128. "name": "Monitor",
  129. "idxs": []
  130. },
  131. "global": {
  132. "count": 2,
  133. "distance": 1,
  134. "self": 72,
  135. "maxRet": 47648758,
  136. "type": "object",
  137. "name": "global",
  138. "idxs": []
  139. },
  140. "daruk": {
  141. "count": 1,
  142. "distance": 7,
  143. "self": 272,
  144. "maxRet": 20440,
  145. "type": "object",
  146. "name": "daruk",
  147. "idxs": []
  148. }
  149. // ...省略等