2014-12-13 12 views
22

Ho il seguente codice Haskell, che implementa una versione semplice dell'utilità della riga di comando "cat" unix. Test delle prestazioni con "time" su un file da 400MB, è circa 3 volte più lento. (lo script esatto che sto usando per testarlo è sotto il codice).Prestazioni Haskell che implementano il programma "cat" di Unix con Data.ByteString

Le mie domande sono:

  1. È questo un test valido di prestazioni?
  2. Come posso rendere questo programma più veloce?
  3. Come identificare i colli di bottiglia delle prestazioni nei programmi Haskell in generale?

Riguardo alle domande 2 e 3: Ho usato GHC -prof, quindi eseguito con + RTS -p, ma sto trovando l'output un po 'non informativo qui.

Source (Main.hs)

module Main where 

import System.IO 
import System.Environment 
import Data.ByteString as BS 

import Control.Monad 

-- Copied from cat source code 
bufsize = 1024*128 

go handle buf = do 
    hPut stdout buf 
    eof <- hIsEOF handle 
    unless eof $ do 
    buf <- hGetSome handle bufsize 
    go handle buf 

main = do 
    file <- fmap Prelude.head getArgs 
    handle <- openFile file ReadMode 
    buf  <- hGetSome handle bufsize 
    hSetBuffering stdin $ BlockBuffering (Just bufsize) 
    hSetBuffering stdout $ BlockBuffering (Just bufsize) 
    go handle buf 

sceneggiatura Timing (run.sh):

#!/usr/bin/env bash 

# Generate 10M lines of silly test data 
yes aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa | head -n 10000000 > huge 

# Compile with optimisation 
ghc -O2 Main.hs 

# Run haskell 
echo "timing Haskell" 
time ./Main huge > /dev/null 

echo "" 
echo "" 

# Run cat 
echo "timing 'cat'" 
time cat huge > /dev/null 

I miei risultati:

timing Haskell 

real 0m0.980s 
user 0m0.296s 
sys  0m0.684s 


timing 'cat' 

real 0m0.304s 
user 0m0.001s 
sys  0m0.302s 

Il rapporto profilatura quando si compila con -Prof e in esecuzione con + RTS -p è qui sotto:

Sat Dec 13 21:26 2014 Time and Allocation Profiling Report (Final) 

    Main +RTS -p -RTS huge 

    total time =  0.92 secs (922 ticks @ 1000 us, 1 processor) 
    total alloc = 7,258,596,176 bytes (excludes profiling overheads) 

COST CENTRE MODULE %time %alloc 

MAIN  MAIN 100.0 100.0 


                 individual  inherited 
COST CENTRE MODULE     no.  entries %time %alloc %time %alloc 

MAIN  MAIN      46   0 100.0 100.0 100.0 100.0 
CAF  GHC.Conc.Signal   84   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.FD     82   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Handle.FD   81   0 0.0 0.0  0.0 0.0 
CAF  System.Posix.Internals 76   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding   70   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding.Iconv  69   0 0.0 0.0  0.0 0.0 
+2

E 'bello vedere che si è aggiunto anche -O2 ottimizzazione. Puoi anche pubblicare il link al rapporto profilato qui. – Sibi

+0

Sibi: L'ho aggiunto, ma sfortunatamente sembra un po 'opaco. L'unica cosa che sembra strana è forse che il numero di "allocazione totale" sia molto grande - quando mi aspetterei che una memoria buffer temporanea venga sovrascritta come ottimizzazione (non sono sicuro che sia possibile). – statusfailed

+4

Invece di 'hGetSome' usa' hGetNonBlocking', aumenta le prestazioni sostanzialmente – Sibi

risposta

15

Questa è solo una risposta parziale cercando di affrontare la seconda domanda:

ho provato qualcosa di simile utilizzando GHC.IO.Buffer API:

module Main where 

import System.IO 
import System.Environment 
import GHC.IO.Buffer 
import Data.ByteString as BS 

import Control.Monad 

-- Copied from cat source code 
bufsize = 1024*128 

go handle bufPtr = do 
    read <- hGetBuf handle bufPtr bufsize 
    when (read > 0) $ do 
    hPutBuf stdout bufPtr read 
    go handle bufPtr 

main = do 
    file <- fmap Prelude.head getArgs 
    handle <- openFile file ReadMode 
    buf  <- newByteBuffer bufsize WriteBuffer 

    withBuffer buf $ go handle 

e sembra avvicinarsi alla performance di 'gatto' , ma ancora decisamente più lento ...

time ./Cat huge > /dev/null 
./Cat huge > /dev/null 0.00s user 0.06s system 76% cpu 0.081 total 

time cat huge > /dev/null 
cat huge > /dev/null 0.00s user 0.05s system 75% cpu 0.063 total 

Penso che utilizzando l'API di buffer, siamo in grado di evitare di allocare in modo esplicito tutte le stringhe di byte di buffer quando si utilizza hGetSome come nel codice originale, ma sto solo indovinando qui e non so neanche che cosa esattamente sta accadendo in entrambi i codici compilati ...

UPDATE: Aggiunta la performance del codice originale sul mio portatile:

time ./Cat2 huge > /dev/null 
./Cat2 huge > /dev/null 0.12s user 0.10s system 99% cpu 0.219 total 

UPDATE 2: Aggiunta di alcuni risultati di profili di base:

Codice originale:

Cat2 +RTS -p -RTS huge 

    total time =  0.21 secs (211 ticks @ 1000 us, 1 processor) 
    total alloc = 6,954,068,112 bytes (excludes profiling overheads) 

COST CENTRE MODULE %time %alloc 

MAIN  MAIN 100.0 100.0 


                 individual  inherited 
COST CENTRE MODULE     no.  entries %time %alloc %time %alloc 

MAIN  MAIN      46   0 100.0 100.0 100.0 100.0 
CAF  GHC.IO.Handle.FD   86   0 0.0 0.0  0.0 0.0 
CAF  GHC.Conc.Signal   82   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding   80   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.FD     79   0 0.0 0.0  0.0 0.0 
CAF  System.Posix.Internals 75   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding.Iconv  72   0 0.0 0.0  0.0 0.0 

Codice Buffer-API:

Cat +RTS -p -RTS huge 

    total time =  0.06 secs (61 ticks @ 1000 us, 1 processor) 
    total alloc = 3,487,712 bytes (excludes profiling overheads) 

COST CENTRE MODULE %time %alloc 

MAIN  MAIN 100.0 98.9 


                 individual  inherited 
COST CENTRE MODULE     no.  entries %time %alloc %time %alloc 

MAIN  MAIN      44   0 100.0 98.9 100.0 100.0 
CAF  GHC.IO.Handle.FD   85   0 0.0 1.0  0.0 1.0 
CAF  GHC.Conc.Signal   82   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding   80   0 0.0 0.1  0.0 0.1 
CAF  GHC.IO.FD    79   0 0.0 0.0  0.0 0.0 
CAF  GHC.IO.Encoding.Iconv 71   0 0.0 0.0  0.0 0.0 

Avviso soprattutto la grande differenza nei costi di allocazione ...

+6

Nota che c'è anche un sovraccarico fisso di circa 10 ms per ogni programma Haskell, quindi se sottrai quello da il tuo timing Haskell è ancora più vicino a 'cat'. –

+1

So di non averlo specificato nella domanda, ma spero di optare per una soluzione Haskell più idiomatica/"di alto livello". Votato per una buona risposta però. – statusfailed

14

La domanda iniziale mi ha fatto pensare che era di trovare un problema di prestazioni nel codice esatto fornito. Dal momento che il commento "Spero di optare per una soluzione Haskell più idiomatica/di alto livello" contraddice tale ipotesi, darò la soluzione idiomatica Haskell ragionevolmente performante.

Il modo in cui mi aspetterei che un programmatore casuale abbia familiarità con Haskell per risolvere questo problema è con i Lazy bytestrings. Ciò consente al programmatore di specificare semplicemente il compito di leggere l'input e di mettere l'output mentre lascia che il compilatore si preoccupi di fare il mucking con i costrutti di buffering e looping.

modulo principale dove

import System.IO 
import System.Environment 
import Data.ByteString.Lazy as BS 

import Control.Monad 

main :: IO() 
main = do 
    file <- fmap Prelude.head getArgs 
    handle <- openFile file ReadMode 
    buf  <- BS.hGetContents handle 
    hPut stdout buf 

Il risultato è al tempo stesso performante più leggibile e meglio che il codice nella domanda iniziale:

timing 'cat' 

real 0m0.075s 
user 0m0.000s 
sys  0m0.074s 
timing strict bytestring with GHC -O2 

real 0m0.254s 
user 0m0.126s 
sys  0m0.127s 
timing strict bytestring with GHC -O2 -fllvm 

real 0m0.267s 
user 0m0.132s 
sys  0m0.134s 
timing lazy bytestring with GHC -O2 

real 0m0.091s 
user 0m0.023s 
sys  0m0.067s 
timing lazy bytestring with GHC -O2 -fllvm 

real 0m0.091s 
user 0m0.021s 
sys  0m0.069s 

Cioè, la soluzione bytestring pigro è del 21% più lento di cat. Mettendo l'ultimo cat per il comportamento preferenziale nella cache si ottiene un tempo di esecuzione di 59 ms che pone la soluzione Haskell al 51% più lentamente.

MODIFICA: Dons suggerito utilizzando IO mappato in memoria modellerebbe più accuratamente il comportamento del gatto. Non sono sicuro di come precisa che la dichiarazione non è che i risultati mmap quasi sempre in migliori prestazioni e questa situazione non fa certo eccezione:

timing memory mapped lazy bytestring with GHC -O2 

real 0m0.008s 
user 0m0.004s 
sys  0m0.003s 

che è stato prodotto da:

module Main where 

import System.IO (stdout) 
import System.Environment 
import System.IO.Posix.MMap.Lazy 
import Data.ByteString.Lazy (hPut) 

import Control.Monad 

main :: IO() 
main = do 
    file <- fmap Prelude.head getArgs 
    buf  <- unsafeMMapFile file 
    hPut stdout buf 
+3

mmap-bytestring dovrebbe essere più vicino al comportamento di 'cat', usando il sistema operativo per eseguire l'allocazione pigra. –

+0

@DonStewart mmap è sempre una grande cosa da ricordare quando si parla di performance, ma è un modo per far esplodere il gatto dalle prestazioni idriche. Non sono sicuro che il mio gatto gnu usi mmap ... infatti strace mostra un numero enorme di letture e scritture. –

+0

@DonStewart In realtà ho provato con bytestring-mmap ed era praticamente alla pari con cat. Buon Consiglio! Di nuovo, però, mi mette a disagio perché mi sembra non idiomatico (sebbene Thomas M. DuBuisson abbia giustamente definito la mia auto-contraddizione) – statusfailed

5

Osservazioni posta festum :

Non sono sicuro di quale sia la domanda ora che le persone l'hanno riavviato un po '. Volevo vedere cosa succedeva con bytestring-mmap, e così ho fatto una versione di pipe per 'correggere' il suo modulo pigro bytestring. https://github.com/michaelt/pipes-bytestring-mmap Di conseguenza ho assemblato tutti questi programmi, usando il metodo di prova sibi s. Gli unici due moduli in https://github.com/michaelt/pipes-bytestring-mmap/tree/master/bench che sembrano tutto fuorché hashell di pane e burro stupidi sono quelli che usano una gestione buffa del buffer esplicita.

In ogni caso, ecco alcuni risultati: Le dimensioni del file aumentano di 10 * mentre ci spostiamo a destra. È interessante vedere fino a che punto i programmi differiscono per dimensioni di file differenti. I programmi che non usano mmap iniziano solo a mostrare il loro carattere come "lineare nella lunghezza del file" a 420M. A quel punto, e dopo, sono quasi tutti uguali, suggerendo che il comportamento piuttosto divergente a dimensioni più piccole non può essere preso troppo sul serio. I file mmap si comportano tutti allo stesso modo (l'uno con l'altro) con alcune curiosità (che ho replicato) Tutto questo è su os x.

4200000   42000000   420000000   4200000000 

timing 'cat' 

real 0m0.006s real 0m0.013s real 0m0.919s real 0m8.154s 
user 0m0.002s user 0m0.002s user 0m0.005s user 0m0.028s 
sys 0m0.003s sys 0m0.009s sys 0m0.223s sys 0m2.179s 


timing lazy bytestring - idiomatic Haskell (following Thomas M. DuBuisson) 

real 0m0.009s real 0m0.025s real 0m0.894s real 0m9.146s 
user 0m0.002s user 0m0.006s user 0m0.078s user 0m0.787s 
sys 0m0.005s sys 0m0.016s sys 0m0.288s sys 0m3.001s 


timing fancy buffering following statusfailed 

real 0m0.014s real 0m0.066s real 0m0.876s real 0m8.686s 
user 0m0.005s user 0m0.028s user 0m0.278s user 0m2.724s 
sys 0m0.007s sys 0m0.035s sys 0m0.424s sys 0m4.232s 


timing fancier use of GHC.Buf following bmk 

real 0m0.011s real 0m0.018s real 0m0.831s real 0m8.218s 
user 0m0.002s user 0m0.003s user 0m0.034s user 0m0.289s 
sys 0m0.006s sys 0m0.013s sys 0m0.236s sys 0m2.447s 


timing Pipes.ByteString following sibi 

real 0m0.012s real 0m0.020s real 0m0.845s real 0m8.241s 
user 0m0.003s user 0m0.004s user 0m0.020s user 0m0.175s 
sys 0m0.007s sys 0m0.014s sys 0m0.239s sys 0m2.509s 

Poi, con mmap

timing Lazy.MMap following dons and Thomas M. DuBuisson 

real 0m0.006s real 0m0.006s real 0m0.037s real 0m0.133s 
user 0m0.002s user 0m0.002s user 0m0.006s user 0m0.051s 
sys 0m0.003s sys 0m0.003s sys 0m0.013s sys 0m0.061 

timing Pipes.ByteString.MMap with SafeT machinery 

real 0m0.006s real 0m0.010s real 0m0.051s real 0m0.196s 
user 0m0.002s user 0m0.004s user 0m0.012s user 0m0.099s 
sys 0m0.003s sys 0m0.005s sys 0m0.016s sys 0m0.072s 


timing Pipes.ByteString.MMap 'withFile' style 

real 0m0.008s real 0m0.008s real 0m0.142s real 0m0.134s 
user 0m0.002s user 0m0.002s user 0m0.007s user 0m0.046s 
sys 0m0.004s sys 0m0.004s sys 0m0.016s sys 0m0.066s