c++ - brk(0) 是否花费了太多时间？

Question

这是 strace -T -ttt -ff -x -y -o pid.trace -p 2145 的输出。跟踪如下。

1503431273.934716 semop(1204093022, {{0, 1, SEM_UNDO}}, 1) = 0 <0.000004>1503431273.934737 clock_gettime(CLOCK_REALTIME, {1503431273, 934741536}) = 0 <0.000004>1503431273.934763 write(6</home/red/samples/debug/hexa.debug>, "17.08.23 01:17:53 [     hexa:2145"..., 79) = 79 <0.000016>1503431273.934960 brk(0)                = 0x1adc000 <0.000004>1503431273.934974 brk(0x1afd000)        = 0x1afd000 <0.000006>1503431273.934994 brk(0)                = 0x1afd000 <0.000003>1503431273.935006 brk(0)                = 0x1afd000 <0.000004>1503431273.935017 brk(0x1afc000)        = 0x1afc000 <0.000008>1503431273.935033 brk(0)                = 0x1afc000 <0.000003>1503431273.935045 brk(0)                = 0x1afc000 <0.000004>1503431273.935057 brk(0)                = 0x1afc000 <0.000004>1503431273.935068 brk(0x1afb000)        = 0x1afb000 <0.000005>1503431273.935080 brk(0)                = 0x1afb000 <0.000003>1503431291.010338 brk(0)                = 0x1afb000 <0.000006>1503431291.010366 brk(0x1b1c000)        = 0x1b1c000 <0.000006>1503431291.010391 brk(0)                = 0x1b1c000 <0.000003>1503431291.010403 brk(0)                = 0x1b1c000 <0.000004>1503431291.010414 brk(0x1b12000)        = 0x1b12000 <0.000008>1503431291.010430 brk(0)                = 0x1b12000 <0.000004>1503431291.010443 brk(0)                = 0x1b12000 <0.000004>1503431291.010455 brk(0)                = 0x1b12000 <0.000003>1503431291.010466 brk(0x1b11000)        = 0x1b11000 <0.000004>1503431291.010478 brk(0)                = 0x1b11000 <0.000004>1503431301.277050 clock_gettime(CLOCK_REALTIME, {1503431301, 277067441}) = 0 <0.000005>1503431301.277094 write(6</home/red/samples/debug/hexa.debug>, "17.08.23 01:18:21 [     hexa:2145"..., 91) = 91 <0.000019>1503431301.277201 clock_gettime(CLOCK_REALTIME, {1503431301, 277216542}) = 0 <0.000005>1503431301.277234 write(6</home/red/samples/debug/hexa.debug>, "17.08.23 01:18:21 [     hexa:2145"..., 126) = 126 <0.000018>1503431301.277296 clock_gettime(CLOCK_REALTIME, {1503431301, 277301142}) = 0 <0.000004>1503431301.277317 write(6</home/red/samples/debug/hexa.debug>, "17.08.23 01:18:21 [     hexa:2145"..., 126) = 126 <0.000012>1503431301.288030 clock_gettime(CLOCK_REALTIME, {1503431301, 288037704}) = 0 <0.000004>

如果您在两个 brk(0)s(请参阅 1503431273.935080 和 1503431291.010478)处查看上面的轨迹，花费了太多时间，分别约为 17 秒和 10 秒 (比较左侧时间)。但右侧的执行时间非常短。我已经在同一个 Redhat Linux box (7.2) 中多次运行该程序，所有运行都在相同的系统调用位置 (brk(0)) 给出相同的计时(微秒差异)。

可能是什么问题？它是在编程级别还是操作系统级别？我没有这方面的源代码，但我知道这是一个 c/c++ 程序。

Answer 1

回答标题中的问题:No, brk(0)不会花费太多时间。

您可以通过查看为系统调用本身报告的时间( <0.000003> ，由 -T 选项添加)来了解这一点。这只有 3 微秒。

左边的值是(绝对)时间戳。但这仅仅意味着进程执行了一个 brk 1503431273.935080 的系统调用和 1503431291.010338 的另一个系统调用。这并不意味着任何单个系统调用都需要 17 秒；这只是意味着进程到达下一个系统调用需要 17 秒。

该进程可能一直在做许多其他事情，例如进行原始计算(消耗 CPU)或未被调度(因为系统正忙于其他程序)。诚然，后一种选择不太可能，因为您说过这发生在程序的多次运行中。因此，我认为最可能的解释是，代码只是花费大量时间进行计算而不需要调用内核(例如，循环中的紧凑数字代码，没有内存分配)。