GHC编译的二进制文件中存在过多神秘的系统时间使用

33

我正在研究自动边界约束搜索的探索。因此,我的起点是SEND MORE MONEY问题,采用无重复非确定性选择解决方案。我改进了这种方法以计算执行的样本数量,以更好地衡量添加搜索约束的影响。

import Control.Monad.State
import Control.Monad.Trans.List
import Control.Monad.Morph
import Data.List (foldl')

type CS a b = StateT [a] (ListT (State Int)) b

select' :: [a] -> [(a, [a])]
select' [] = []
select' (x:xs) = (x, xs) : [(y, x:ys) | ~(y, ys) <- select' xs]

select :: CS a a
select = do
    i <- lift . lift $ get
    xs <- get
    lift . lift . put $! i + length xs
    hoist (ListT . return) (StateT select')

runCS :: CS a b -> [a] -> ([b], Int)
runCS a xs = flip runState 0 . runListT $ evalStateT a xs

fromDigits :: [Int] -> Int
fromDigits = foldl' (\x y -> 10 * x + y) 0

sendMoreMoney :: ([(Int, Int, Int)], Int)
sendMoreMoney = flip runCS [0..9] $ do
    [s,e,n,d,m,o,r,y] <- replicateM 8 select
    let send  = fromDigits [s,e,n,d]
        more  = fromDigits [m,o,r,e]
        money = fromDigits [m,o,n,e,y]
    guard $ s /= 0 && m /= 0 && send + more == money
    return (send, more, money)

main :: IO ()
main = print sendMoreMoney

它能够正常工作,得出正确的结果,并且在搜索过程中保持了平坦的堆栈轮廓。但即使如此,速度仍然很慢。与不计算选项相比,速度要慢大约20倍。即使这样也并不可怕。为了收集这些性能数据,我可以忍受付出巨大的代价。

但是我仍然不希望性能变得毫无意义地糟糕,所以我决定寻找一些简单易行的性能优化方法。在这个过程中,我发现了一些令人困惑的结果。

$ ghc -O2 -Wall -fforce-recomp -rtsopts statefulbacktrack.hs
[1 of 1] Compiling Main             ( statefulbacktrack.hs, statefulbacktrack.o )
Linking statefulbacktrack ...
$ time ./statefulbacktrack
([(9567,1085,10652)],2606500)

real    0m6.960s
user    0m3.880s
sys     0m2.968s

那个系统时间简直荒谬。程序只输出了一次。所有的输出都去哪了?我的下一步是检查strace

$ strace -cf ./statefulbacktrack
([(9567,1085,10652)],2606500)
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
 98.38    0.033798        1469        23           munmap
  1.08    0.000370           0     21273           rt_sigprocmask
  0.26    0.000090           0     10638           clock_gettime
  0.21    0.000073           0     10638           getrusage
  0.07    0.000023           4         6           mprotect
  0.00    0.000000           0         8           read
  0.00    0.000000           0         1           write
  0.00    0.000000           0       144       134 open
  0.00    0.000000           0        10           close
  0.00    0.000000           0         1           execve
  0.00    0.000000           0         9         9 access
  0.00    0.000000           0         3           brk
  0.00    0.000000           0         1           ioctl
  0.00    0.000000           0       847           sigreturn
  0.00    0.000000           0         1           uname
  0.00    0.000000           0         1           select
  0.00    0.000000           0        13           rt_sigaction
  0.00    0.000000           0         1           getrlimit
  0.00    0.000000           0       387           mmap2
  0.00    0.000000           0        16        15 stat64
  0.00    0.000000           0        10           fstat64
  0.00    0.000000           0         1         1 futex
  0.00    0.000000           0         1           set_thread_area
  0.00    0.000000           0         1           set_tid_address
  0.00    0.000000           0         1           timer_create
  0.00    0.000000           0         2           timer_settime
  0.00    0.000000           0         1           timer_delete
  0.00    0.000000           0         1           set_robust_list
------ ----------- ----------- --------- --------- ----------------
100.00    0.034354                 44039       159 total

那么..根据 strace 的信息,仅有 0.034354 秒的时间用于系统调用。

time 报告的其余 sys 时间去哪了?

另外一个数据点:GC 时间非常高。 有没有简单的方法来降低它?

$ ./statefulbacktrack +RTS -s
([(9567,1085,10652)],2606500)
   5,541,572,660 bytes allocated in the heap
   1,465,208,164 bytes copied during GC
      27,317,868 bytes maximum residency (66 sample(s))
         635,056 bytes maximum slop
              65 MB total memory in use (0 MB lost due to fragmentation)

                                     Tot time (elapsed)  Avg pause  Max pause
  Gen  0     10568 colls,     0 par    1.924s   2.658s     0.0003s    0.0081s
  Gen  1        66 colls,     0 par    0.696s   2.226s     0.0337s    0.1059s

  INIT    time    0.000s  (  0.001s elapsed)
  MUT     time    1.656s  (  2.279s elapsed)
  GC      time    2.620s  (  4.884s elapsed)
  EXIT    time    0.000s  (  0.009s elapsed)
  Total   time    4.276s  (  7.172s elapsed)

  %GC     time      61.3%  (68.1% elapsed)

  Alloc rate    3,346,131,972 bytes per MUT second

  Productivity  38.7% of total user, 23.1% of total elapsed

系统信息:

$ ghc --version
The Glorious Glasgow Haskell Compilation System, version 7.10.1
$ uname -a
Linux debian 3.2.0-4-686-pae #1 SMP Debian 3.2.68-1+deb7u1 i686 GNU/Linux

在Windows 8.1上托管的VMWare Player 7.10中运行一个Debian 7虚拟机。


6
一位朋友在非虚拟化的 Linux 系统上使用 GHC 7.6 运行了这段代码,并在输出中看到了 sys 0m0.136s。很可能是虚拟化导致了这个结果。 - Carl
munmap 函数几乎肯定被垃圾回收器用于管理内存池。带有复制式垃圾回收器的函数式语言不适合在虚拟机上运行。建议在裸机上运行。 - Gene
1个回答

5
请确保在 +RTS -s 后添加 -H128 到您的构建命令行中。
您的 eval 看起来很好,所以您可以继续进行。
如果您真的想要解决这个虚拟机上的迟缓问题,请提高虚拟机的线程优先级(如果需要,还可以轻微提高虚拟机控制台的优先级)。
另一个意外的惩罚将是由于 GC 的同步确认(因为这是 SMP Debian 在多核系统上)。在任何多核系统上,GC 都将执行更多的 VM 操作,这部分解释了 61% 的 GC 统计和您的 strace 和 time 差异。对于大多数情况,这些统计数据都不可靠。
您做得非常好,特别是如果您正在使用 i7 或更高版本的处理器。
如果使用 -H128 选项无法解决问题,我会感到惊讶。
我是新来的,请让我知道是否需要进一步帮助或在奖励之前需要什么。

这是一款i7处理器。您能否添加几句关于为什么在这种情况下i7特别不适合运行虚拟机的原因? - Carl
幸运的是,真正的多核i7(英特尔代号Nehalem)和后代系统具有每个核心独立的L1缓存(绝对最快的RAM)和每个核心256kb的L2缓存也在芯片上(处理器旁边的RAM)。 对于您正在建模的非确定性系统,独立的每个核心缓存对于更好的性能至关重要。 - miniscule
i7芯片组及更高版本的另一个好处是英特尔重新引入了超线程技术(每个处理器两个核心)。希望您的项目进展顺利,并且您能够发现更多超出预期的东西... - miniscule
你尝试了我提到的优先级增加技巧,能否从系统中挤出更多性能? - miniscule
我可能能够... 不过我并不是那么担心。我只是想弄清楚发生了什么。如果我没有得到比你更好的答案,我会为此奖励悬赏金的。我只是等到最后一天才决定。 :) - Carl
显示剩余2条评论

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接