Haskell分析 - clock_gettime

Has*_*ani 6 profiling haskell clock

我正在运行一个执行长计算的Haskell程序.经过一些分析和追踪,我注意到以下几点:

$ /usr/bin/time -v ./hl test.hl
9000045000050000
Command being timed: "./hl test.hl +RTS"
User time (seconds): 1.43
System time (seconds): 1.15
Run Code Online (Sandbox Code Playgroud)

它使用了大量的系统时间,即使我的代码没有显式调用任何系统调用(它读取文件并解释其中的一些代码).

使用strace -ttT运行它会显示很多对计时器的调用:

17:04:52.454513 clock_gettime(CLOCK_THREAD_CPUTIME_ID, {1, 282721271}) = 0 <0.000529>
17:04:52.456223 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000720>
17:04:52.458749 rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0 <0.000239>
17:04:52.460288 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {1, 285126436}) = 0 <0.000255>
17:04:52.461650 --- SIGVTALRM {si_signo=SIGVTALRM, si_code=SI_TIMER, si_pid=0, si_uid=0, si_value=0} ---
17:04:52.462242 rt_sigreturn()          = 0 <0.000458>
Run Code Online (Sandbox Code Playgroud)

我以为它可能是RTS时钟,所以我禁用它并重新运行:

$ /usr/bin/time -v ./hl test.hl +RTS -V0
9000045000050000
Command being timed: "./hl test.hl +RTS -V0"
User time (seconds): 1.73
System time (seconds): 0.85
Run Code Online (Sandbox Code Playgroud)

除了实际的SIGVTALRM之外,strace输出似乎几乎相同:

17:05:16.409729 clock_gettime(CLOCK_PROCESS_CPUTIME_ID, {0, 155881514}) = 0 <0.000378>
17:05:16.410746 clock_gettime(CLOCK_MONOTONIC, {2184631, 597586194}) = 0 <0.000432>
17:05:16.412724 clock_gettime(CLOCK_THREAD_CPUTIME_ID, {0, 156994988}) = 0 <0.000290>
17:05:16.413832 rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 <0.000245>
17:05:16.415017 rt_sigprocmask(SIG_BLOCK, [INT], [], 8) = 0 <0.000305>
Run Code Online (Sandbox Code Playgroud)

我有几个问题:

  1. 为什么Haskell重复调用clock_gettime?
  2. 有没有办法禁用此功能?

scl*_*clv 0

我查看了clock_gettimeGHC RTS 中的调用位置,发现它在调用中使用,而该调用又是库的TimerManagergetMonotonicTime中超时的基础,IO 管理器使用该库来轮询句柄、文件、系统调用等。MIO论文是 IO 管理器上相对较新的良好资源。无论如何,我不认为您能够消除这些电话。GHC.Event

另请注意,虽然您看到很多时钟调用,但这并不意味着它们是花费最多时间的系统调用,我认为这与 GC、实际执行 IO 等更多相关。