Разница в производительности скомпилированного ускоренного кода запускалась из ghci и shell

Question

Разница в производительности скомпилированного ускоренного кода запускалась из ghci и shell

проблема

Здравствуйте, я использую ускоренную библиотеку для создания приложения, позволяющего пользователю интерактивно вызывать функции, которые обрабатывают изображения, поэтому я основываюсь и расширяю ghci с помощью ghc api.

Проблема заключается в том, что при запуске скомпилированного исполняемого файла из оболочки вычисления выполняются менее чем за 100 мс (чуть меньше 80), а при запуске того же скомпилированного кода в ghci для завершения требуется более 100 мс (в среднем чуть больше 140).

Ресурсы

Пример кода + журналы выполнения: https://gist.github.com/zgredzik/15a437c87d3d8d03b8fc

Описание

Прежде всего: тесты были проведены после того, как ядро CUDA было скомпилировано (сама компиляция добавила дополнительные 2 секунды, но это не так).

При запуске скомпилированного исполняемого файла из оболочки вычисления выполняются менее чем за 10 мс. (shell first run а также second shell run иметь разные аргументы, чтобы убедиться, что данные нигде не были кэшированы).

При попытке запустить тот же код из ghci и перебирать входные данные, вычисления занимают более 100 мс. Я понимаю, что интерпретируемый код медленнее, чем скомпилированный, но я загружаю тот же скомпилированный код в сеансе ghci и вызываю ту же самую привязку верхнего уровня (packedFunction). Я явно набрал его, чтобы убедиться, что он специализирован (те же результаты, что и при использовании прагмы SPECIALIZED).

Однако вычисления занимают менее 10 мс, если я запускаю main функция в ghci (даже при изменении входных данных с :set args между последовательными звонками).

Скомпилировал Main.hs с ghc -o main Main.hs -O2 -dynamic -threaded

Мне интересно, откуда взялись накладные расходы. У кого-нибудь есть предложения относительно того, почему это происходит?

Упрощенная версия примера, размещенного 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,09 с.

$ 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,25 с

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

33

performance haskell profiling ghci accelerate-haskell

Источник

user2370280 18 дек '14 в 07:51

1 ответ

Решение

Другие вопросы по тегам performance haskell profiling ghci accelerate-haskell

user1641629 22 янв '15 в 09:14 2015-01-22 09:14 · Accepted Answer · 2015-01-22 09:14

Я исследовал accelerate а также accelerate-cuda и поместите некоторый отладочный код для измерения времени как в ghci, так и в скомпилированной, оптимизированной версии.

Результаты ниже, вы можете увидеть трассировку стека и время выполнения.

GHCI Run

$ 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

Как мы видим, есть две основные проблемы: оценка fromList (Z:.1000000) [1..1000000] :: Vector Double что занимает 69 мс при GHCI (106 мс - 37 мс), и performGC вызов, который занимает дополнительно 57 мс (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.121653 с при ghci и 0.035162 с при скомпилированной версии
executeGC принимает 0.044876s под ghci и 0.00031s в скомпилированной версии.

Это может быть другой вопрос, но, может быть, кто-то знает: можем ли мы как-то настроить сборщик мусора, чтобы он работал быстрее под ghci?