0

这是 的输出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 写入（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 写入（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 写（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 盒子 (7.2) 中多次运行了这个程序，所有运行都在系统调用的同一位置 (brk(0)) 给出了相同的时间(微秒差异)。

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

4

1 回答 1

3

回答标题中的问题：不，brk(0)不需要太多时间。

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

左边的值是（绝对）时间戳。但这仅仅意味着该进程在 1503431273.935080 处执行了brk系统调用，在 1503431291.010338 处执行了另一个系统调用。这并不意味着任何一个系统调用都需要 17 秒。这只是意味着该进程需要 17 秒才能到达下一个系统调用。

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

于 2017-08-23T18:43:15.683 回答