【问题标题】:Difference in performance of compiled accelerate code ran from ghci and shell从 ghci 和 shell 运行的已编译加速代码的性能差异
【发布时间】:2015-02-16 22:43:34
【问题描述】:

问题

您好,我正在使用加速库创建一个应用程序,允许用户以交互方式调用处理图像的函数,这就是我使用 ghc api 基于和扩展 ghci 的原因。

问题在于,当从 shell 运行编译后的可执行文件时,计算在 100 毫秒(略小于 80 毫秒)内完成,而在 ghci 中运行相同的编译代码则需要超过 100 毫秒(平均多于 140 毫秒)完成。

资源

示例代码+执行日志: https://gist.github.com/zgredzik/15a437c87d3d8d03b8fc

说明

首先:测试是在编译 CUDA 内核之后运行的(编译本身增加了 2 秒,但事实并非如此)。

当从 shell 运行编译后的可执行文件时,计算在 10 毫秒内完成。 (shell first runsecond shell run 传递了不同的参数以确保数据没有缓存在任何地方)。

当尝试从 ghci 运行相同的代码并摆弄输入数据时,计算时间超过 100 毫秒。我知道解释代码比编译代码慢,但我在 ghci 会话中加载相同的编译代码并调用相同的顶级绑定 (packedFunction)。我已明确键入它以确保它是专用的(与使用 SPECIALIZED pragma 的结果相同)。

但是,如果我在 ghci 中运行 main 函数(即使在连续调用之间使用 :set args 更改输入数据),计算时间确实不到 10 毫秒。

ghc -o main Main.hs -O2 -dynamic -threaded编译Main.hs

我想知道开销从何而来。有人对为什么会发生这种情况有任何建议吗?


remdezx 发布的示例的简化版本:

{-# LANGUAGE OverloadedStrings #-}

module Main where

import Data.Array.Accelerate as A
import Data.Array.Accelerate.CUDA as C
import Data.Time.Clock       (diffUTCTime, getCurrentTime)

main :: IO ()
main = do
    start <- getCurrentTime
    print $ C.run $ A.maximum $ A.map (+1) $ A.use (fromList (Z:.1000000) [1..1000000] :: Vector Double)
    end   <- getCurrentTime
    print $ diffUTCTime end start

当我编译并执行它需要 0,09s 来完成。

$ ghc -O2 Main.hs -o main -threaded
[1 of 1] Compiling Main             ( Main.hs, Main.o )
Linking main ...
$ ./main
Array (Z) [1000001.0]
0.092906s

但是当我预编译它并在解释器中运行它需要 0,25s

$ ghc -O2 Main.hs -c -dynamic
$ ghci Main
ghci> main
Array (Z) [1000001.0]
0.258224s

【问题讨论】:

  • 您能打开分析并获取报告吗?
  • 你的意思是:downloads.haskell.org/~ghc/7.8.3/docs/html/users_guide/…?我会尽快尝试的。
  • 我在Data.Array.Accelerate.CUDA.run 中注入了一些时间测量代码,我注意到当acclerate 库加载到ghci 时,run 的执行速度比在可执行文件中使用时慢3 倍。我尝试添加以下编译指示但没有效果。 {-# SPECIALISE run :: Acc (Array DIM2 Double) -&gt; (Array DIM2 Double) #-} {-# SPECIALISE run :: Acc (Array DIM2 Float) -&gt; (Array DIM2 Float) #-}。我们可以为 ghci 优化这个 run 函数吗?
  • 我已经更新了要点 - 添加了分析报告 (main.prof)
  • @ChristianConkle,我从这里 stackoverflow.com/questions/27881725/… 尝试了您的测试,并将此重写规则注入到加速 cuda 库中 - 结果:isOptimised=True,但代码仍然很慢。

标签: performance haskell profiling ghci accelerate-haskell


【解决方案1】:

我调查了accelerateaccelerate-cuda 并放置了一些调试代码来测量在 ghci 和已编译、优化的版本中的时间。

结果如下,你可以看到堆栈跟踪和执行时间。

ghci 运行

$ ghc -O2 -dynamic -c -threaded Main.hs && ghci 
GHCi, version 7.8.3: http://www.haskell.org/ghc/  :? for help
…
Loading package ghc-prim ... linking ... done.
Loading package integer-gmp ... linking ... done.
Loading package base ... linking ... done.
Ok, modules loaded: Main.
Prelude Main> Loading package transformers-0.3.0.0 ... linking ... done.
…
Loading package array-0.5.0.0 ... linking ... done.
(...)
Loading package accelerate-cuda-0.15.0.0 ... linking ... done.
>>>>> run
>>>>> runAsyncIn.execute
>>>>>  runAsyncIn.seq ctx
<<<<<  runAsyncIn.seq ctx: 4.1609e-2 CPU  0.041493s TOTAL
>>>>>  runAsyncIn.seq a
<<<<<  runAsyncIn.seq a: 1.0e-6 CPU  0.000001s TOTAL
>>>>>  runAsyncIn.seq acc
>>>>>   convertAccWith True
<<<<<   convertAccWith: 0.0 CPU  0.000017s TOTAL
<<<<<  runAsyncIn.seq acc: 2.68e-4 CPU  0.000219s TOTAL
>>>>>  evalCUDA
>>>>>   push
<<<<<   push: 0.0 CPU  0.000002s TOTAL
>>>>>   evalStateT
>>>>>    runAsyncIn.compileAcc
>>>>>     compileOpenAcc
>>>>>      compileOpenAcc.traveuseAcc.Alet
>>>>>      compileOpenAcc.traveuseAcc.Use
>>>>>       compileOpenAcc.traveuseAcc.use3
>>>>>       compileOpenAcc.traveuseAcc.use1
<<<<<       compileOpenAcc.traveuseAcc.use1: 0.0 CPU  0.000001s TOTAL
>>>>>       compileOpenAcc.traveuseAcc.use2
>>>>>        compileOpenAcc.traveuseAcc.seq arr
<<<<<        compileOpenAcc.traveuseAcc.seq arr: 0.105716 CPU  0.105501s TOTAL
>>>>>        useArrayAsync
<<<<<        useArrayAsync: 1.234e-3 CPU  0.001505s TOTAL
<<<<<       compileOpenAcc.traveuseAcc.use2: 0.108012 CPU  0.108015s TOTAL
<<<<<       compileOpenAcc.traveuseAcc.use3: 0.108539 CPU  0.108663s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Use: 0.109375 CPU  0.109005s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Fold1
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0.000001s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0.000001s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Fold1: 2.059e-3 CPU  0.002384s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Alet: 0.111434 CPU  0.112034s TOTAL
<<<<<     compileOpenAcc: 0.11197 CPU  0.112615s TOTAL
<<<<<    runAsyncIn.compileAcc: 0.11197 CPU  0.112833s TOTAL
>>>>>    runAsyncIn.dumpStats
<<<<<    runAsyncIn.dumpStats: 2.0e-6 CPU  0.000001s TOTAL
>>>>>    runAsyncIn.executeAcc
>>>>>     executeAcc
<<<<<     executeAcc: 8.96e-4 CPU  0.00049s TOTAL
<<<<<    runAsyncIn.executeAcc: 9.36e-4 CPU  0.0007s TOTAL
>>>>>    runAsyncIn.collect
<<<<<    runAsyncIn.collect: 0.0 CPU  0.000027s TOTAL
<<<<<   evalStateT: 0.114156 CPU  0.115327s TOTAL
>>>>>   pop
<<<<<   pop: 0.0 CPU  0.000002s TOTAL
>>>>>   performGC
<<<<<   performGC: 5.7246e-2 CPU  0.057814s TOTAL
<<<<<  evalCUDA: 0.17295 CPU  0.173943s TOTAL
<<<<< runAsyncIn.execute: 0.215475 CPU  0.216563s TOTAL
<<<<< run: 0.215523 CPU  0.216771s TOTAL
Array (Z) [1000001.0]
0.217148s
Prelude Main> Leaving GHCi.

编译后的代码运行

$ ghc -O2 -threaded Main.hs && ./Main
[1 of 1] Compiling Main             ( Main.hs, Main.o )
Linking Main ...
>>>>> run
>>>>> runAsyncIn.execute
>>>>>  runAsyncIn.seq ctx
<<<<<  runAsyncIn.seq ctx: 4.0639e-2 CPU  0.041498s TOTAL
>>>>>  runAsyncIn.seq a
<<<<<  runAsyncIn.seq a: 1.0e-6 CPU  0.000001s TOTAL
>>>>>  runAsyncIn.seq acc
>>>>>   convertAccWith True
<<<<<   convertAccWith: 1.2e-5 CPU  0.000005s TOTAL
<<<<<  runAsyncIn.seq acc: 1.15e-4 CPU  0.000061s TOTAL
>>>>>  evalCUDA
>>>>>   push
<<<<<   push: 2.0e-6 CPU  0.000002s TOTAL
>>>>>   evalStateT
>>>>>    runAsyncIn.compileAcc
>>>>>     compileOpenAcc
>>>>>      compileOpenAcc.traveuseAcc.Alet
>>>>>      compileOpenAcc.traveuseAcc.Use
>>>>>       compileOpenAcc.traveuseAcc.use3
>>>>>       compileOpenAcc.traveuseAcc.use1
<<<<<       compileOpenAcc.traveuseAcc.use1: 0.0 CPU  0.000001s TOTAL
>>>>>       compileOpenAcc.traveuseAcc.use2
>>>>>        compileOpenAcc.traveuseAcc.seq arr
<<<<<        compileOpenAcc.traveuseAcc.seq arr: 3.6651e-2 CPU  0.03712s TOTAL
>>>>>        useArrayAsync
<<<<<        useArrayAsync: 1.427e-3 CPU  0.001427s TOTAL
<<<<<       compileOpenAcc.traveuseAcc.use2: 3.8776e-2 CPU  0.039152s TOTAL
<<<<<       compileOpenAcc.traveuseAcc.use3: 3.8794e-2 CPU  0.039207s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Use: 3.8808e-2 CPU  0.03923s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Fold1
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 2.0e-6 CPU  0.000001s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 2.0e-6 CPU  0.000001s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0.000001s TOTAL
>>>>>      compileOpenAcc.traveuseAcc.Avar
<<<<<      compileOpenAcc.traveuseAcc.Avar: 0.0 CPU  0.000001s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Fold1: 1.342e-3 CPU  0.001284s TOTAL
<<<<<      compileOpenAcc.traveuseAcc.Alet: 4.0197e-2 CPU  0.040578s TOTAL
<<<<<     compileOpenAcc: 4.0248e-2 CPU  0.040895s TOTAL
<<<<<    runAsyncIn.compileAcc: 4.0834e-2 CPU  0.04103s TOTAL
>>>>>    runAsyncIn.dumpStats
<<<<<    runAsyncIn.dumpStats: 0.0 CPU  0s TOTAL
>>>>>    runAsyncIn.executeAcc
>>>>>     executeAcc
<<<<<     executeAcc: 2.87e-4 CPU  0.000403s TOTAL
<<<<<    runAsyncIn.executeAcc: 2.87e-4 CPU  0.000488s TOTAL
>>>>>    runAsyncIn.collect
<<<<<    runAsyncIn.collect: 9.2e-5 CPU  0.000049s TOTAL
<<<<<   evalStateT: 4.1213e-2 CPU  0.041739s TOTAL
>>>>>   pop
<<<<<   pop: 0.0 CPU  0.000002s TOTAL
>>>>>   performGC
<<<<<   performGC: 9.41e-4 CPU  0.000861s TOTAL
<<<<<  evalCUDA: 4.3308e-2 CPU  0.042893s TOTAL
<<<<< runAsyncIn.execute: 8.5154e-2 CPU  0.084815s TOTAL
<<<<< run: 8.5372e-2 CPU  0.085035s TOTAL
Array (Z) [1000001.0]
0.085169s

我们可以看到有两个主要问题:在 ghci (106ms - 37ms) 下评估 fromList (Z:.1000000) [1..1000000] :: Vector Double 需要额外的 69 毫秒,以及需要 57 毫秒的 performGC 调用 额外(58 毫秒 - 1 毫秒)。这两个总结了在 ghci 下执行和在编译版本中执行的区别。

我想,在编译程序中,RTS 管理内存的方式与 ghci 不同,因此分配和 gc 可以更快。我们也可以只测试这部分评估下面的代码(它根本不需要 CUDA):

import Data.Array.Accelerate.Array.Sugar
import Data.Time.Clock                   (diffUTCTime, getCurrentTime)
import System.Mem                        (performGC)


main :: IO ()
main = do
    measure $ seq (fromList (Z:.1000000) [1..1000000] :: Vector Double) $ return ()
    measure $ performGC

measure action = do
    start <- getCurrentTime
    action
    end   <- getCurrentTime
    print $ diffUTCTime end start

结果:

  • 评估向量需要 0.121653s 在 ghci 和 0.035162s 在 编译后的版本
  • performGC 在 ghci 下耗时 0.044876s0.00031s 在编译版本中。

这可能是另一个问题,但也许有人知道:我们能否以某种方式调整垃圾收集器以在 ghci 下更快地工作?

【讨论】:

    猜你喜欢
    • 1970-01-01
    • 1970-01-01
    • 2019-03-26
    • 2014-02-02
    • 1970-01-01
    • 1970-01-01
    • 2012-08-09
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多