hyj1991/easy-monitor

疑似bug:incremental_marking_duration_last_record始终为4294967296

TooBug opened this issue · 17 comments

TooBug commented 
[2022-06-07 12:53:56] [info] [cpu] [84281] [0] [2.0.1] cpu_usage(%) cpu_now: 0.000000, cpu_15: 1.266667, cpu_30: 0.633333, cpu_60: 0.316667, cpu_180: 0.327778, cpu_300: 0.566116, cpu_600: 0.566116
[2022-06-07 12:53:56] [info] [memory] [84281] [0] [2.0.1] memory_usage(byte) rss: 41488384, heap_used: 65711304, heap_available: 2132578752, heap_total: 67944448, heap_limit: 2197815296, heap_executeable: 835584, total_physical_size: 66776552, malloced_memory: 155800, amount_of_external_allocated_memory: 2752769, new_space_size: 1048576, new_space_used: 873440, new_space_available: 174016, new_space_committed: 871568, old_space_size: 24784896, old_space_used: 24115352, old_space_available: 546376, old_space_committed: 24323440, code_space_size: 692224, code_space_used: 392096, code_space_available: 157952, code_space_committed: 417376, map_space_size: 2101248, map_space_used: 1314480, map_space_available: 782104, map_space_committed: 2075720, lo_space_size: 39006208, lo_space_used: 38980344, lo_space_available: 0, lo_space_committed: 39006208, read_only_space_size: 262144, read_only_space_used: 32808, read_only_space_available: 0, read_only_space_committed: 33088, new_lo_space_size: 0, new_lo_space_used: 0, new_lo_space_available: 1047456, new_lo_space_committed: 0, code_lo_space_size: 49152, code_lo_space_used: 2784, code_lo_space_available: 0, code_lo_space_committed: 49152, 
[2022-06-07 12:53:56] [info] [gc] [84281] [0] [2.0.1] uptime: 244, total_gc_times: 17, total_gc_duration: 51, total_scavange_duration: 26, total_marksweep_duration: 25, total_incremental_marking_duration: 0, gc_time_during_last_record: 1, scavange_duration_last_record: 1, marksweep_duration_last_record: 0, incremental_marking_duration_last_record: 4294967296
[2022-06-07 12:53:56] [info] [uv] [84281] [0] [2.0.1] active_handles: 12, active_file_handles: 7, active_and_ref_file_handles: 7, active_tcp_handles: 3, active_and_ref_tcp_handles: 3, active_udp_handles: 0, active_and_ref_udp_handles: 0, active_timer_handles: 1, active_and_ref_timer_handles: 1
[2022-06-07 12:53:56] [info] [http] [84281] [0] [2.0.1] live_http_request: 0, http_response_close: 0, http_response_sent: 0, http_request_timeout: 0, http_patch_timeout: 30, http_rt: 0.00
[2022-06-07 12:53:57] [info] [cpu] [84282] [0] [2.0.1] cpu_usage(%) cpu_now: 0.000000, cpu_15: 0.000000, cpu_30: 0.000000, cpu_60: 0.000000, cpu_180: 0.000000, cpu_300: 0.095041, cpu_600: 0.095041
[2022-06-07 12:53:57] [info] [memory] [84282] [0] [2.0.1] memory_usage(byte) rss: 29573120, heap_used: 68134632, heap_available: 2130249088, heap_total: 71450624, heap_limit: 2197815296, heap_executeable: 835584, total_physical_size: 69511552, malloced_memory: 155800, amount_of_external_allocated_memory: 2637306, new_space_size: 1048576, new_space_used: 232080, new_space_available: 815376, new_space_committed: 233200, old_space_size: 27930624, old_space_used: 27183896, old_space_available: 614768, old_space_committed: 27382264, code_space_size: 692224, code_space_used: 417248, code_space_available: 238112, code_space_committed: 571520, map_space_size: 2625536, map_space_used: 1453440, map_space_available: 1168704, map_space_committed: 2399960, lo_space_size: 38842368, lo_space_used: 38812376, lo_space_available: 0, lo_space_committed: 38842368, read_only_space_size: 262144, read_only_space_used: 32808, read_only_space_available: 0, read_only_space_committed: 33088, new_lo_space_size: 0, new_lo_space_used: 0, new_lo_space_available: 1047456, new_lo_space_committed: 0, code_lo_space_size: 49152, code_lo_space_used: 2784, code_lo_space_available: 0, code_lo_space_committed: 49152, 
[2022-06-07 12:53:57] [info] [gc] [84282] [0] [2.0.1] uptime: 244, total_gc_times: 7, total_gc_duration: 20, total_scavange_duration: 1, total_marksweep_duration: 19, total_incremental_marking_duration: 0, gc_time_during_last_record: 0, scavange_duration_last_record: 0, marksweep_duration_last_record: 0, incremental_marking_duration_last_record: 4294967296
[2022-06-07 12:53:57] [info] [uv] [84282] [0] [2.0.1] active_handles: 3, active_file_handles: 0, active_and_ref_file_handles: 0, active_tcp_handles: 1, active_and_ref_tcp_handles: 1, active_udp_handles: 0, active_and_ref_udp_handles: 0, active_timer_handles: 1, active_and_ref_timer_handles: 1
[2022-06-07 12:53:57] [info] [http] [84282] [0] [2.0.1] live_http_request: 0, http_response_close: 0, http_response_sent: 0, http_request_timeout: 0, http_patch_timeout: 30, http_rt: 0.00
[2022-06-07 12:54:57] [info] [cpu] [84281] [0] [2.0.1] cpu_usage(%) cpu_now: 0.000000, cpu_15: 1.333333, cpu_30: 0.666667, cpu_60: 0.333333, cpu_180: 0.327778, cpu_300: 0.420000, cpu_600: 0.518152
[2022-06-07 12:54:57] [info] [memory] [84281] [0] [2.0.1] memory_usage(byte) rss: 39120896, heap_used: 65715592, heap_available: 2132359064, heap_total: 68206592, heap_limit: 2197815296, heap_executeable: 835584, total_physical_size: 66735864, malloced_memory: 155800, amount_of_external_allocated_memory: 2761129, new_space_size: 1048576, new_space_used: 523584, new_space_available: 523872, new_space_committed: 524696, old_space_size: 25047040, old_space_used: 24451928, old_space_available: 253936, old_space_committed: 24628856, code_space_size: 692224, code_space_used: 392864, code_space_available: 157952, code_space_committed: 418144, map_space_size: 2101248, map_space_used: 1331280, map_space_available: 767144, map_space_committed: 2075720, lo_space_size: 39006208, lo_space_used: 38980344, lo_space_available: 0, lo_space_committed: 39006208, read_only_space_size: 262144, read_only_space_used: 32808, read_only_space_available: 0, read_only_space_committed: 33088, new_lo_space_size: 0, new_lo_space_used: 0, new_lo_space_available: 1047456, new_lo_space_committed: 0, code_lo_space_size: 49152, code_lo_space_used: 2784, code_lo_space_available: 0, code_lo_space_committed: 49152, 
[2022-06-07 12:54:57] [info] [gc] [84281] [0] [2.0.1] uptime: 305, total_gc_times: 20, total_gc_duration: 54, total_scavange_duration: 29, total_marksweep_duration: 25, total_incremental_marking_duration: 0, gc_time_during_last_record: 3, scavange_duration_last_record: 3, marksweep_duration_last_record: 0, incremental_marking_duration_last_record: 4294967296
[2022-06-07 12:54:57] [info] [uv] [84281] [0] [2.0.1] active_handles: 12, active_file_handles: 7, active_and_ref_file_handles: 7, active_tcp_handles: 3, active_and_ref_tcp_handles: 3, active_udp_handles: 0, active_and_ref_udp_handles: 0, active_timer_handles: 1, active_and_ref_timer_handles: 1
[2022-06-07 12:54:57] [info] [http] [84281] [0] [2.0.1] live_http_request: 0, http_response_close: 0, http_response_sent: 0, http_request_timeout: 0, http_patch_timeout: 30, http_rt: 0.00
[2022-06-07 12:54:58] [info] [cpu] [84282] [0] [2.0.1] cpu_usage(%) cpu_now: 0.000000, cpu_15: 0.000000, cpu_30: 0.000000, cpu_60: 0.000000, cpu_180: 0.000000, cpu_300: 0.076667, cpu_600: 0.075908
[2022-06-07 12:54:58] [info] [memory] [84282] [0] [2.0.1] memory_usage(byte) rss: 29065216, heap_used: 68193952, heap_available: 2130190416, heap_total: 71450624, heap_limit: 2197815296, heap_executeable: 835584, total_physical_size: 69570824, malloced_memory: 155800, amount_of_external_allocated_memory: 2637582, new_space_size: 1048576, new_space_used: 290752, new_space_available: 756704, new_space_committed: 291824, old_space_size: 27930624, old_space_used: 27184544, old_space_available: 614768, old_space_committed: 27382912, code_space_size: 692224, code_space_used: 417248, code_space_available: 238112, code_space_committed: 571520, map_space_size: 2625536, map_space_used: 1453440, map_space_available: 1168704, map_space_committed: 2399960, lo_space_size: 38842368, lo_space_used: 38812376, lo_space_available: 0, lo_space_committed: 38842368, read_only_space_size: 262144, read_only_space_used: 32808, read_only_space_available: 0, read_only_space_committed: 33088, new_lo_space_size: 0, new_lo_space_used: 0, new_lo_space_available: 1047456, new_lo_space_committed: 0, code_lo_space_size: 49152, code_lo_space_used: 2784, code_lo_space_available: 0, code_lo_space_committed: 49152, 
[2022-06-07 12:54:58] [info] [gc] [84282] [0] [2.0.1] uptime: 305, total_gc_times: 7, total_gc_duration: 20, total_scavange_duration: 1, total_marksweep_duration: 19, total_incremental_marking_duration: 0, gc_time_during_last_record: 0, scavange_duration_last_record: 0, marksweep_duration_last_record: 0, incremental_marking_duration_last_record: 4294967296
[2022-06-07 12:54:58] [info] [uv] [84282] [0] [2.0.1] active_handles: 3, active_file_handles: 0, active_and_ref_file_handles: 0, active_tcp_handles: 1, active_and_ref_tcp_handles: 1, active_udp_handles: 0, active_and_ref_udp_handles: 0, active_timer_handles: 1, active_and_ref_timer_handles: 1
[2022-06-07 12:54:58] [info] [http] [84282] [0] [2.0.1] live_http_request: 0, http_response_close: 0, http_response_sent: 0, http_request_timeout: 0, http_patch_timeout: 30, http_rt: 0.00

如上面的日志，incremental_marking_duration_last_record值始终为4294967296，它的二进制是100000000000000000000000000000000，刚好超过32位无符号整数的范围。这导致xtransit-manager入库时报错：

2022-06-07 12:57:53,690 ERROR 28373 [-/127.0.0.1/-/4ms POST /xtransit/log] nodejs.ER_WARN_DATA_OUT_OF_RANGEError: ER_WARN_DATA_OUT_OF_RANGE: Out of range value for column 'incremental_marking_duration_last_record' at row 1
    at Query.Sequence._packetToError (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/sequences/Sequence.js:47:14)
    at Query.ErrorPacket (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/sequences/Query.js:79:18)
    at Protocol._parsePacket (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/Protocol.js:291:23)
    at Parser._parsePacket (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/Parser.js:433:10)
    at Parser.write (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/Parser.js:43:10)
    at Protocol.write (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/protocol/Protocol.js:38:16)
    at Socket.<anonymous> (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/Connection.js:88:28)
    at Socket.<anonymous> (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/Connection.js:526:10)
    at Socket.emit (events.js:198:13)
    at addChunk (_stream_readable.js:288:12)
    --------------------
    at Pool.query (/data/easy-monitor/xtransit-manager/node_modules/mysql/lib/Pool.js:199:23)
    at /data/easy-monitor/xtransit-manager/node_modules/pify/index.js:29:7
    at new Promise (<anonymous>)
    at Pool.<anonymous> (/data/easy-monitor/xtransit-manager/node_modules/pify/index.js:12:10)
    at Pool.ret [as query] (/data/easy-monitor/xtransit-manager/node_modules/pify/index.js:56:34)
    at RDSClient.proto._query (/data/easy-monitor/xtransit-manager/node_modules/ali-rds/lib/client.js:38:20)
    at RDSClient.proto.query (/data/easy-monitor/xtransit-manager/node_modules/ali-rds/lib/operator.js:54:29)
    at proto.query.next (<anonymous>)
    at onFulfilled (/data/easy-monitor/xtransit-manager/node_modules/co/index.js:65:19)
    at /data/easy-monitor/xtransit-manager/node_modules/co/index.js:54:5
    sql: INSERT INTO osinfo_07 (app, agent, log_time, position, version, total_memory, free_memory, disks, response_codes,  uptime, used_cpu, cpu_count, load1, load5, load15, node_count, total_gc_times, total_gc_duration, total_scavange_duration, total_marksweep_duration, total_incremental_marking_duration, gc_time_during_last_record, scavange_duration_last_record, marksweep_duration_last_record, incremental_marking_duration_last_record, live_http_request, http_response_close, http_response_sent, http_request_timeout, http_patch_timeout, http_rt) values (1, 'toobug-air.local', '2022-06-07 12:57:53', 1, '', 0, 0, '{}', '{}', 0, 0, 0, 0, 0, 0, 0, 16, 38, 16, 22, 0, 0.5, 0.5, 0, 4294967296, 0, 0, 0, 0, 0, 0)
code: "ER_WARN_DATA_OUT_OF_RANGE"
errno: 1264
sqlMessage: "Out of range value for column 'incremental_marking_duration_last_record' at row 1"
sqlState: "22003"
index: 0
sql: "INSERT INTO osinfo_07 (app, agent, log_time, position, version, total_memory, free_memory, disks, response_codes,  uptime, used_cpu, cpu_count, load1, load5, load15, node_count, total_gc_times, total_gc_duration, total_scavange_duration, total_marksweep_duration, total_incremental_marking_duration, gc_time_during_last_record, scavange_duration_last_record, marksweep_duration_last_record, incremental_marking_duration_last_record, live_http_request, http_response_close, http_response_sent, http_request_timeout, http_patch_timeout, http_rt) values (1, 'toobug-air.local', '2022-06-07 12:57:53', 1, '', 0, 0, '{}', '{}', 0, 0, 0, 0, 0, 0, 0, 16, 38, 16, 22, 0, 0.5, 0.5, 0, 4294967296, 0, 0, 0, 0, 0, 0)"
name: "ER_WARN_DATA_OUT_OF_RANGEError"
pid: 28373
hostname: xxx

在控制台中，进程的插件状态看到的全部正常，但是看不到进程的监控数据，不确定是否与此有关，如无关的话再另外开issue。

image

hyj1991 commented

看起来确实有问题，我确认下

hyj1991 commented

有办法复现这个场景吗，看逻辑上并不会有问题

TooBug commented

我这边是egg的应用，现在在我自己电脑上是必现的。我尝试看看是否有稳定的重现办法。

hyj1991 commented

另外可以看下切换 node 版本后这个问题是否还存在

TooBug commented

继续重现中，目前有一些现象先反馈一下：

  1. 同一个项目，在不同的mac机器上试过，无论是否m1，都可以复现；
  2. Node版本都用的12.x，Node 10应该是不被支持的，下载不到二进制文件，Node 16是否也没支持，似乎也下载不到？其它版本还没试验，因为我们内部有些包也需要二进制文件包，需要对项目进行裁剪后再试。
hyj1991 commented

xprofiler@2.x 支持的是 node-v12.x ~ node-v18.x，对应的预编译包在：https://registry.npmmirror.com/binary.html?path=xprofiler/v2.0.1/

你没有下载到看下是不是没有配置 mirror host，不配置的话默认指向 github release page，这个在国内连通性不太好可能会导致下载失败从而 fall back to local compile

install 的时候配置下 mirror host 指向国内镜像即可：npm install --xprofiler_binary_host_mirror=https://npmmirror.com/mirrors/xprofiler

hyj1991 commented

https://github.com/X-Profiler/xprofiler/blob/master/src/logbypass/gc.cc#L76-L77

这个问题感觉还挺奇怪的，total_incremental_marking_duration 和 incremental_marking_duration_last_record 是同时记录的，只是前者是启动后一直累加，后者每次采集后会清 0 以只记录采集周期内的耗时

那么出问题的是 incremental_marking_duration_last_record，而 total_incremental_marking_duration 没问题，很奇怪。

最好能给个最小复现的代码，我再 debug 看看，光看这里的逻辑看不出哪里会产生问题，而且我这边已经大量在生产使用过了，没遇到这个问题

TooBug commented

换到linux上用node 16跑起来了，没有问题，一切正常。
mac上换用node 16也正常了。

上面说的Node 16下载不到二进制包的问题，可能是npm 8的行为和旧版本不一致，看日志是没有走node-pre-gyp，而是直接运行了编译，这个问题可以另说。

目前先划定问题范围：mac系统node 12

这里我继续跟进一下，希望可以保留issue，有后续继续回复到这里。

hyj1991 commented

具体是 node 12 的哪一个版本？

TooBug commented

v12.22.1

TooBug commented

重新初始化了一下egg项目，必现。

环境：

  • 硬件
    • MacBook Air (M1, 2020)
    • iMac (Retina 5K, 27-inch, 2017) --这台只跑了公司项目，没有再跑这个复现项目
  • 系统 macOS 12.4
  • node v12.22.1 (arch: x64)

下面是所有我输入的命令和回显（为方便查看，加了些空行分段/ni命令是使用了@antfu/ni，等价于npm i）：

➜  tmp mkdir easy-monitor-demo
➜  tmp cd easy-monitor-demo





➜  easy-monitor-demo node -v
v12.22.1





➜  easy-monitor-demo npm init egg --type=simple
npx: 428 安装成功，用时 24.556 秒
[egg-init] use registry: https://registry.npmjs.org
[egg-init] target dir is /Users/toobug/work/tmp/easy-monitor-demo
[egg-init] fetching npm info of egg-init-config
[egg-init] use boilerplate: simple(egg-boilerplate-simple)
[egg-init] fetching npm info of egg-boilerplate-simple
[egg-init] downloading https://registry.npmjs.org/egg-boilerplate-simple/-/egg-boilerplate-simple-3.3.1.tgz
[egg-init] extract to /var/folders/4s/wc4y3pm91vq5pvncldgvnlbc0000gn/T/egg-init-boilerplate
[egg-init] collecting boilerplate config...
? project name easy-monitor-demo
? project description
? project author
? cookie security keys 1654675783538_1624
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/.autod.conf.js
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/.eslintignore
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/.eslintrc
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/README.md
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/.gitignore
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/package.json
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/app/router.js
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/config/config.default.js
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/config/plugin.js
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/app/controller/home.js
[egg-init] write to /Users/toobug/work/tmp/easy-monitor-demo/test/app/controller/home.test.js
[egg-init] usage:
      - cd /Users/toobug/work/tmp/easy-monitor-demo
      - npm install
      - npm start / npm run dev / npm test







➜  easy-monitor-demo npm i
npm WARN deprecated babel-eslint@8.2.6: babel-eslint is now @babel/eslint-parser. This package will no longer receive updates.
npm WARN deprecated core-js@2.6.12: core-js@<3.3 is no longer maintained and not recommended for usage due to the number of issues. Because of the V8 engine whims, feature detection in old core-js versions could cause a slowdown up to 100x even if nothing is polyfilled. Please, upgrade your dependencies to the actual version of core-js.
npm WARN deprecated formidable@1.2.6: Please upgrade to latest, formidable@v2 or formidable@v3! Check these notes: https://bit.ly/2ZEqIau
npm WARN deprecated resolve-url@0.2.1: https://github.com/lydell/resolve-url#deprecated
npm WARN deprecated urix@0.1.0: Please see https://github.com/lydell/urix#deprecated
npm WARN deprecated debug@3.2.6: Debug versions >=3.2.0 <3.2.7 || >=4 <4.3.1 have a low-severity ReDos regression when used in a Node.js environment. It is recommended you upgrade to 3.2.7 or 4.3.1. (https://github.com/visionmedia/debug/issues/797)
npm WARN deprecated mkdirp@0.5.4: Legacy versions of mkdirp are no longer supported. Please update to mkdirp 1.x. (Note that the API surface has changed to use Promises in 1.x.)

> core-js@2.6.12 postinstall /Users/toobug/work/tmp/easy-monitor-demo/node_modules/core-js
> node -e "try{require('./postinstall')}catch(e){}"

Thank you for using core-js ( https://github.com/zloirock/core-js ) for polyfilling JavaScript standard library!

The project needs your help! Please consider supporting of core-js on Open Collective or Patreon:
> https://opencollective.com/core-js
> https://www.patreon.com/zloirock

Also, the author of core-js ( https://github.com/zloirock ) is looking for a good job -)


> core-js-pure@3.22.8 postinstall /Users/toobug/work/tmp/easy-monitor-demo/node_modules/core-js-pure
> node -e "try{require('./postinstall')}catch(e){}"

Thank you for using core-js ( https://github.com/zloirock/core-js ) for polyfilling JavaScript standard library!

The project needs your help! Please consider supporting of core-js:
> https://opencollective.com/core-js
> https://patreon.com/zloirock
> bitcoin: bc1qlea7544qtsmj2rayg0lthvza9fau63ux0fstcz

Also, the author of core-js ( https://github.com/zloirock ) is looking for a good job -)


> es5-ext@0.10.61 postinstall /Users/toobug/work/tmp/easy-monitor-demo/node_modules/es5-ext
>  node -e "try{require('./_postinstall')}catch(e){}" || exit 0


> egg-ci@1.19.1 postinstall /Users/toobug/work/tmp/easy-monitor-demo/node_modules/egg-ci
> node install.js

[egg-ci] create /Users/toobug/work/tmp/easy-monitor-demo/.travis.yml success
[egg-ci] create /Users/toobug/work/tmp/easy-monitor-demo/appveyor.yml success
[egg-ci] create /Users/toobug/work/tmp/easy-monitor-demo/.github/workflows/nodejs.yml success
npm notice created a lockfile as package-lock.json. You should commit this file.
npm WARN co-mocha@1.2.2 requires a peer of mocha@>=1.18 <6 but none is installed. You must install peer dependencies yourself.

added 1357 packages from 1145 contributors and audited 1357 packages in 135.81s

84 packages are looking for funding
  run `npm fund` for details

found 29 vulnerabilities (8 moderate, 15 high, 6 critical)
  run `npm audit fix` to fix them, or `npm audit` for details






➜  easy-monitor-demo npm run dev

> easy-monitor-demo@1.0.0 dev /Users/toobug/work/tmp/easy-monitor-demo
> egg-bin dev

[egg-ts-helper] create typings/app/controller/index.d.ts (2ms)
[egg-ts-helper] create typings/config/index.d.ts (11ms)
[egg-ts-helper] create typings/config/plugin.d.ts (1ms)
[egg-ts-helper] create typings/app/index.d.ts (0ms)
2022-06-08 16:17:24,607 INFO 51989 [master] node version v12.22.1
'use strict';
2022-06-08 16:17:24,607 INFO 51989 [master] egg version 2.35.0
/* eslint valid-jsdoc: "off" */

2022-06-08 16:17:25,124 INFO 51989 [master] agent_worker#1:51993 started (515ms)
/* eslint valid-jsdoc: "off" */

'use strict';

/**
 * @param {Egg.EggAppInfo} appInfo app info
 */
module.exports = appInfo => {
  /**
   * built-in config
2022-06-08 16:17:25,671 INFO 51989 [master] egg started on http://127.0.0.1:7001 (1063ms)
2022-06-08 16:17:42,969 INFO 51989 [master] master is killed by signal SIGINT, closing
2022-06-08 16:17:42,972 INFO 51989 [master] system memory: total 8589934592, free 20340736
2022-06-08 16:17:42,972 INFO 51989 [master] process info: heap_limit 2197815296, heap_used 36949224
2022-06-08 16:17:42,973 INFO 51989 [master] send kill SIGTERM to app workers, will exit with code:0 after 1000ms
2022-06-08 16:17:42,974 INFO 51989 [master] wait 1000ms







➜  easy-monitor-demo ni egg-xtransit

> xprofiler@2.0.1 install /Users/toobug/work/tmp/easy-monitor-demo/node_modules/xprofiler
> node-pre-gyp install --fallback-to-build

[xprofiler] Success: "/Users/toobug/work/tmp/easy-monitor-demo/node_modules/xprofiler/build/binding/Release/node-v72-darwin-x64/xprofiler.node" is installed via remote
npm WARN co-mocha@1.2.2 requires a peer of mocha@>=1.18 <6 but none is installed. You must install peer dependencies yourself.

+ egg-xtransit@2.0.0
added 116 packages from 67 contributors and audited 1473 packages in 16.735s

85 packages are looking for funding
  run `npm fund` for details

found 29 vulnerabilities (8 moderate, 15 high, 6 critical)
  run `npm audit fix` to fix them, or `npm audit` for details
➜  easy-monitor-demo vi config/plugin.js
➜  easy-monitor-demo vi config/config.default.js
➜  easy-monitor-demo vi config/config.default.js
➜  easy-monitor-demo npm run dev

> easy-monitor-demo@1.0.0 dev /Users/toobug/work/tmp/easy-monitor-demo
> egg-bin dev

[egg-ts-helper] create typings/app/controller/index.d.ts (2ms)
[egg-ts-helper] create typings/config/index.d.ts (10ms)
[egg-ts-helper] create typings/config/plugin.d.ts (1ms)
[egg-ts-helper] create typings/app/index.d.ts (0ms)
2022-06-08 16:20:28,898 INFO 53482 [master] node version v12.22.1
2022-06-08 16:20:28,900 INFO 53482 [master] egg version 2.35.0
2022-06-08 16:20:29,851 INFO 53482 [master] agent_worker#1:53485 started (948ms)
2022-06-08 16:20:30,436 INFO 53482 [master] egg started on http://127.0.0.1:7001 (1536ms)
2022-06-08 16:20:30,441 INFO 53485 [xtransit] xtransit start.
2022-06-08 16:20:30,441 INFO 53485 [xtransit] websocket client connecting to ws://172.28.249.10:9090...
2022-06-08 16:20:30,533 INFO 53485 [xtransit] websocket client has been connected.
hyj1991 commented

我来确认下这个问题

TooBug commented

update: linux(centos 6)下使用node v12.22.12 是正常的。如果排查过程中有必要的话我再对齐patch版本测试一下。

hyj1991 commented

这个问题大概找到原因了，vsnprintf 没办法执行 -Wformt 的精度匹配检查，gc 的值用的是 uint32_t，但是可变参数中的 format 定义的是 %lu，我本来认为 %u -> %lu 是放大，不会有精度问题

但是咨询了下内部的同学，这种精度不匹配属于未定义行为，可能产生未知问题，比如这里的精度溢出，也可能没有问题。

所以计划在所有的 logbypass 输出的地方加上编译时的精度匹配校验，来解决这类问题。

TooBug commented

非常高效，辛苦了！期待新版本发布。

hyj1991 commented

在 xprofiler@2.1.0 中已修复。