2014-12-18 12 views
32

ProblemRóżnica w wydajności skompilowany kod przyspieszyć biegła od ghci i powłoki

Witam, używam przyspieszyć biblioteki do tworzenia aplikacji, pozwalając użytkownikowi na interaktywne funkcje przetwarzania obrazów zadzwonić, dlatego jestem bazując na i rozszerzając ghci używając ghc api.

Problem polega na tym, że podczas uruchamiania skompilowanego pliku wykonywalnego z powłoki obliczenia wykonywane są poniżej 100ms (nieco mniej niż 80), podczas gdy uruchamianie tego samego skompilowanego kodu w ghci zajmuje ponad 100ms (średnio nieco ponad 140) skończyć.

Resources

kod + wykonanie przykładowe kłody: https://gist.github.com/zgredzik/15a437c87d3d8d03b8fc

Opis

Przede wszystkim: badania były pobiegł za jądro CUDA został skompilowany (kompilacja sama dodany dodatkowy 2 sekundy, ale tak nie jest).

Podczas wykonywania skompilowanego pliku wykonywalnego z powłoki obliczenia są wykonywane w mniej niż 10 ms. (shell first run i second shell run mają przekazane różne argumenty, aby upewnić się, że dane nie zostały w pamięci podręcznej nigdzie).

Podczas próby uruchomienia tego samego kodu z ghci i manipulowania danymi wejściowymi, obliczenia zajmują 100 ms. Rozumiem, że zinterpretowany kod jest wolniejszy niż skompilowany, ale ładuję ten sam skompilowany kod w ramach sesji ghci i wywołuję to samo powiązanie najwyższego poziomu (packedFunction). Napisałem go jawnie, aby upewnić się, że jest wyspecjalizowany (takie same wyniki jak użycie SPECJALIZOWANEJ pragma).

Jednak obliczenia zajmują mniej niż 10 ms, jeśli uruchomię funkcję main w ghci (nawet przy zmianie danych wejściowych na :set args między kolejnymi połączeniami).

skompilował Main.hs z ghc -o main Main.hs -O2 -dynamic -threaded

zastanawiam gdzie napowietrznej pochodzi. Czy ktoś ma jakieś sugestie, dlaczego tak się dzieje?


Uproszczona wersja przykład wysłana przez 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 

Kiedy skompilować i wykonać to trwa 0,09s, aby zakończyć.

$ 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 

Ale kiedy precompile go i uruchomić w tłumacza trwa 0,25s

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

Czy możesz włączyć profilowanie i otrzymać raport? –

+0

masz na myśli tutaj: https://downloads.haskell.org/~ghc/7.8.3/docs/html/users_guide/profiling.html? Spróbuję najszybciej. –

+1

Wpadłem trochę kodu pomiarowego czasu do 'Data.Array.Accelerate.CUDA.run' i zauważyłem, że kiedy' aklerate' biblioteka jest ładowana do ghci, 'run' wykonuje 3 razy wolniej niż wtedy, gdy jest użyte w pliku wykonywalnym . Próbowałem dodać kolejne pragmy, ale bez efektu. '{- # SPECIALIZE run :: Acc (Array DIM2 Double) -> (Array DIM2 Double) # -} {- Uruchom # SPECIALIZE :: Acc (Array DIM2 Float) -> (Array DIM2 Float) # -}' . Czy możemy zoptymalizować jakoś tę funkcję uruchamiania dla ghci? – remdezx

Odpowiedz

2

badałem accelerate i accelerate-cuda i umieścić jakiś kod diagnostyczny do pomiaru czasu, zarówno pod ghci iw skompilowana, zoptymalizowana wersja.

Wyniki znajdują się poniżej, możesz zobaczyć czas i czas wykonania stosu.

run 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. 

skompilowany run kod

$ 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 

Jak widać istnieją dwa główne problemy: ocena fromList (Z:.1000000) [1..1000000] :: Vector Double która odbywa 69 ms dodatkowych pod ghci (106ms - 37ms) i performGC połączenie, które trwa 57 ms dodatkowych (58 ms - 1 ms). Te dwie sumy do różnicy między wykonaniem pod ghci i w wersji skompilowanej.

Przypuszczam, że w skompilowanym programie RTS zarządza pamięcią w inny sposób niż w ghci, więc alokacja i gc mogą być szybsze. Możemy również sprawdzić tylko tę część oceniający poniżej kod (nie wymaga CUDA w ogóle):

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 

Wyniki:

  • oceny wektor bierze 0.121653s pod ghci i 0.035162s w skompilowana wersja
  • performGC trwa 0.044876s pod ghci i 0.00031s w skompilowanej wersji.

To może być kolejne pytanie, ale może ktoś wie: Czy możemy dostroić jakoś garbage collector do pracy szybciej pod ghci?