2015-10-15 6 views
19

Ich versuche zu verstehen, wie teuer ein (grün) Gewinde in Haskell (GHC 7.10.1 auf OS X 10.10.5) wirklich ist. Ich bin mir bewusst, dass es im Vergleich zu einem echten OS-Thread sehr billig ist, sowohl für die Speichernutzung als auch für die CPU.Haskell/GHC pro Thread Speicher kostet

rechts, so begann ich mit Gabeln n (grün) Fäden ein Super einfaches Programm zu schreiben (die ausgezeichnete async Bibliothek) und dann schläft nur jeden Thread für m Sekunden.

Nun, das ist einfach genug:

$ cat PerTheadMem.hs 
import Control.Concurrent (threadDelay) 
import Control.Concurrent.Async (mapConcurrently) 
import System.Environment (getArgs) 

main = do 
    args <- getArgs 
    let (numThreads, sleep) = case args of 
           numS:sleepS:[] -> (read numS :: Int, read sleepS :: Int) 
           _ -> error "wrong args" 
    mapConcurrently (\_ -> threadDelay (sleep*1000*1000)) [1..numThreads] 

und vor allem wollen wir kompilieren und ausführen:

$ ghc --version 
The Glorious Glasgow Haskell Compilation System, version 7.10.1 
$ ghc -rtsopts -O3 -prof -auto-all -caf-all PerTheadMem.hs 
$ time ./PerTheadMem 100000 10 +RTS -sstderr 

die 100k Fäden Gabel sollte und 10s in jeder warten und uns dann einige drucken Informationen:

$ time ./PerTheadMem 100000 10 +RTS -sstderr 
340,942,368 bytes allocated in the heap 
880,767,000 bytes copied during GC 
164,702,328 bytes maximum residency (11 sample(s)) 
21,736,080 bytes maximum slop 
350 MB total memory in use (0 MB lost due to fragmentation) 

Tot time (elapsed) Avg pause Max pause 
Gen 0  648 colls,  0 par 0.373s 0.415s  0.0006s 0.0223s 
Gen 1  11 colls,  0 par 0.298s 0.431s  0.0392s 0.1535s 

INIT time 0.000s ( 0.000s elapsed) 
MUT  time 79.062s (92.803s elapsed) 
GC  time 0.670s ( 0.846s elapsed) 
RP  time 0.000s ( 0.000s elapsed) 
PROF time 0.000s ( 0.000s elapsed) 
EXIT time 0.065s ( 0.091s elapsed) 
Total time 79.798s (93.740s elapsed) 

%GC  time  0.8% (0.9% elapsed) 

Alloc rate 4,312,344 bytes per MUT second 

Productivity 99.2% of total user, 84.4% of total elapsed 


real 1m33.757s 
user 1m19.799s 
sys 0m2.260s 

Es dauerte ziemlich lange (1m33.757s) gegeben, dass jeder Thread nur soll nur für 10s warten, aber wir haben es bauen ohne Gewinde so fair genug für heute. Alles in allem haben wir 350 MB benutzt, das ist nicht schlecht, das sind 3,5 KB pro Thread. Da die anfängliche Stapelgröße (-ki is 1 KB).

Richtig, aber jetzt wollen wir kompilieren in Gewinde Modus und sehen, ob wir schneller erhalten können:

$ ghc -rtsopts -O3 -prof -auto-all -caf-all -threaded PerTheadMem.hs 
$ time ./PerTheadMem 100000 10 +RTS -sstderr 
3,996,165,664 bytes allocated in the heap 
2,294,502,968 bytes copied during GC 
3,443,038,400 bytes maximum residency (20 sample(s)) 
14,842,600 bytes maximum slop 
3657 MB total memory in use (0 MB lost due to fragmentation) 

Tot time (elapsed) Avg pause Max pause 
Gen 0  6435 colls,  0 par 0.860s 1.022s  0.0002s 0.0028s 
Gen 1  20 colls,  0 par 2.206s 2.740s  0.1370s 0.3874s 

TASKS: 4 (1 bound, 3 peak workers (3 total), using -N1) 

SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled) 

INIT time 0.000s ( 0.001s elapsed) 
MUT  time 0.879s ( 8.534s elapsed) 
GC  time 3.066s ( 3.762s elapsed) 
RP  time 0.000s ( 0.000s elapsed) 
PROF time 0.000s ( 0.000s elapsed) 
EXIT time 0.074s ( 0.247s elapsed) 
Total time 4.021s (12.545s elapsed) 

Alloc rate 4,544,893,364 bytes per MUT second 

Productivity 23.7% of total user, 7.6% of total elapsed 

gc_alloc_block_sync: 0 
whitehole_spin: 0 
gen[0].sync: 0 
gen[1].sync: 0 

real 0m12.565s 
user 0m4.021s 
sys 0m1.154s 

Wow, viel schneller, nur 12s jetzt viel besser. Von Activity Monitor habe ich gesehen, dass es ungefähr 4 OS-Threads für die 100k grünen Threads verwendet hat, was sinnvoll ist.

Jedoch 3657 MB Gesamtspeicher! Das ist 10x mehr als die verwendete Version ohne Gewinde ...

Bis jetzt habe ich kein Profiling mit -prof oder -hy oder so gemacht. Um zu untersuchen, ein bisschen mehr Ich habe dann einige Haufen Profilierung (-hy) in separaten läuft. Die Speichernutzung hat sich in beiden Fällen nicht geändert, die Heap-Profiling-Graphen sehen interessanterweise anders aus (links: nicht-threaded, rechts: threaded), aber ich kann den Grund für die 10x-Differenz nicht finden.

Diffing die Profiling-Ausgabe (.prof Dateien) Ich kann auch keinen wirklichen Unterschied finden. prof diffs

Deshalb meine Frage: Woher kommt der 10x Unterschied in der Speichernutzung?

EDIT: Nur um es zu erwähnen: Der gleiche Unterschied gilt, wenn das Programm nicht einmal mit Profiling-Unterstützung kompiliert wird. So läuft time ./PerTheadMem 100000 10 +RTS -sstderr mit ghc -rtsopts -threaded -fforce-recomp PerTheadMem.hs ist 3559 MB. Und mit ghc -rtsopts -fforce-recomp PerTheadMem.hs ist es 395 MB.

EDIT 2: Unter Linux (GHC 7.10.2 auf Linux 3.13.0-32-generiC#57-Ubuntu SMP, x86_64) das gleiche passiert: ohne Gewinde 460 MB in 1m28.538s und Gewinde ist 3483 MB 12.604s ist. /usr/bin/time -v ... Berichte Maximum resident set size (kbytes): 413684 und Maximum resident set size (kbytes): 1645384 jeweils.

EDIT 3: verändert sich auch das Programm forkIO direkt zu verwenden:

import Control.Concurrent (threadDelay, forkIO) 
import Control.Concurrent.MVar 
import Control.Monad (mapM_) 
import System.Environment (getArgs) 

main = do 
    args <- getArgs 
    let (numThreads, sleep) = case args of 
           numS:sleepS:[] -> (read numS :: Int, read sleepS :: Int) 
           _ -> error "wrong args" 
    mvar <- newEmptyMVar 
    mapM_ (\_ -> forkIO $ threadDelay (sleep*1000*1000) >> putMVar mvar()) 
      [1..numThreads] 
    mapM_ (\_ -> takeMVar mvar) [1..numThreads] 

Und es ändert nichts: ohne Gewinde: 152 MB, mit Gewinde: 3308 MB.

+1

Ich frage mich, wie viel Overhead-Profiling hinzugefügt wird. Unter Linux können Sie 'time' überzeugen, Speicherstatistiken auszugeben. Was passiert, wenn Sie ohne Profiling kompilieren und das Betriebssystem nach Speicherstatistiken fragen? – MathematicalOrchid

+1

@MathematicalOrchid Ich habe vier Läufe insgesamt gemacht, 2 ohne Profilierung (1 Gewinde/1 ohne Gewinde), 2 mit Profilierung. Die '-stderr'-Ausgabe hat sich nicht geändert. Die Bilder stammen von den letzten beiden Läufen. Außerdem habe ich die Verwendung von Mem im Activity Monitor überprüft und konnte keinen großen Unterschied zwischen w/o Profiling sehen. –

+0

OK, einen Versuch wert. Ich habe jetzt keine Ideen mehr. : -} – MathematicalOrchid

Antwort

10

IMHO, der Schuldige ist threadDelay. * threadDelay ** verwendet viel Speicher. Hier ist ein Programm, das Ihrem entspricht, das sich besser mit Speicher verhält. Es stellt sicher, dass alle Threads gleichzeitig ausgeführt werden, indem eine lange laufende Berechnung ausgeführt wird.

uBound = 38 
lBound = 34 

doSomething :: Integer -> Integer 
doSomething 0 = 1 
doSomething 1 = 1 
doSomething n | n < uBound && n > 0 = let 
        a = doSomething (n-1) 
        b = doSomething (n-2) 
       in a `seq` b `seq` (a + b) 
       | otherwise = doSomething (n `mod` uBound) 

e :: Chan Integer -> Int -> IO() 
e mvar i = 
    do 
     let y = doSomething . fromIntegral $ lBound + (fromIntegral i `mod` (uBound - lBound)) 
     y `seq` writeChan mvar y 

main = 
    do 
     args <- getArgs 
     let (numThreads, sleep) = case args of 
            numS:sleepS:[] -> (read numS :: Int, read sleepS :: Int) 
            _ -> error "wrong args" 
      dld = (sleep*1000*1000) 
     chan <- newChan 
     mapM_ (\i -> forkIO $ e chan i) [1..numThreads] 
     putStrLn "All threads created" 
     mapM_ (\_ -> readChan chan >>= putStrLn . show) [1..numThreads] 
     putStrLn "All read" 

Und hier sind die Timing-Statistiken:

$ ghc -rtsopts -O -threaded test.hs 
$ ./test 200 10 +RTS -sstderr -N4 

133,541,985,480 bytes allocated in the heap 
    176,531,576 bytes copied during GC 
     356,384 bytes maximum residency (16 sample(s)) 
      94,256 bytes maximum slop 
       4 MB total memory in use (0 MB lost due to fragmentation) 

            Tot time (elapsed) Avg pause Max pause 
    Gen 0  64246 colls, 64246 par 1.185s 0.901s  0.0000s 0.0274s 
    Gen 1  16 colls, 15 par 0.004s 0.002s  0.0001s 0.0002s 

    Parallel GC work balance: 65.96% (serial 0%, perfect 100%) 

    TASKS: 10 (1 bound, 9 peak workers (9 total), using -N4) 

    SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled) 

    INIT time 0.000s ( 0.003s elapsed) 
    MUT  time 63.747s (16.333s elapsed) 
    GC  time 1.189s ( 0.903s elapsed) 
    EXIT time 0.001s ( 0.000s elapsed) 
    Total time 64.938s (17.239s elapsed) 

    Alloc rate 2,094,861,384 bytes per MUT second 

    Productivity 98.2% of total user, 369.8% of total elapsed 

gc_alloc_block_sync: 98548 
whitehole_spin: 0 
gen[0].sync: 0 
gen[1].sync: 2 

Maximale Aufenthalt ist bei etwa 1,5 kb pro Faden. Ich habe ein wenig mit der Anzahl der Threads und der Lauflänge der Berechnung gespielt. Da Threads unmittelbar nach forkIO mit der Ausführung von Aufgaben beginnen, dauert das Erstellen von 100000 Threads sehr lange. Aber die Ergebnisse für 1000 Threads gehalten.

Hier ist ein weiteres Programm, in dem threadDelay „herausgerechnet“ wurde, dieser keine CPU nicht verwendet und kann leicht mit 100000 Threads ausgeführt werden:

e :: MVar() -> MVar() -> IO() 
e start end = 
    do 
     takeMVar start 
     putMVar end() 

main = 
    do 
     args <- getArgs 
     let (numThreads, sleep) = case args of 
            numS:sleepS:[] -> (read numS :: Int, read sleepS :: Int) 
            _ -> error "wrong args" 
     starts <- mapM (const newEmptyMVar) [1..numThreads] 
     ends <- mapM (const newEmptyMVar) [1..numThreads] 
     mapM_ (\ (start,end) -> forkIO $ e start end) (zip starts ends) 
     mapM_ (\ start -> putMVar start()) starts 
     putStrLn "All threads created" 
     threadDelay (sleep * 1000 * 1000) 
     mapM_ (\ end -> takeMVar end) ends 
     putStrLn "All done" 

und die Ergebnisse:

 129,270,632 bytes allocated in the heap 
    404,154,872 bytes copied during GC 
     77,844,160 bytes maximum residency (10 sample(s)) 
     10,929,688 bytes maximum slop 
      165 MB total memory in use (0 MB lost due to fragmentation) 

            Tot time (elapsed) Avg pause Max pause 
    Gen 0  128 colls, 128 par 0.178s 0.079s  0.0006s 0.0152s 
    Gen 1  10 colls,  9 par 0.367s 0.137s  0.0137s 0.0325s 

    Parallel GC work balance: 50.09% (serial 0%, perfect 100%) 

    TASKS: 10 (1 bound, 9 peak workers (9 total), using -N4) 

    SPARKS: 0 (0 converted, 0 overflowed, 0 dud, 0 GC'd, 0 fizzled) 

    INIT time 0.000s ( 0.001s elapsed) 
    MUT  time 0.189s (10.094s elapsed) 
    GC  time 0.545s ( 0.217s elapsed) 
    EXIT time 0.001s ( 0.002s elapsed) 
    Total time 0.735s (10.313s elapsed) 

    Alloc rate 685,509,460 bytes per MUT second 

    Productivity 25.9% of total user, 1.8% of total elapsed 

Auf meinem i5 dauert es weniger als eine Sekunde, um die 100000 Threads zu erstellen und die "Start" -Mvar zu setzen. Die Spitzenresidenz liegt bei ungefähr 778 Bytes pro Thread, überhaupt nicht schlecht!


Überprüfung threadDelay Implementierung, sehen wir, dass es für die mit und ohne Gewinde Fall effektiv ist anders:

https://hackage.haskell.org/package/base-4.8.1.0/docs/src/GHC.Conc.IO.html#threadDelay

Dann hier: https://hackage.haskell.org/package/base-4.8.1.0/docs/src/GHC.Event.TimerManager.html

, die genug unschuldig aussieht. Aber eine ältere Version der Basis hat eine obskure Schreibweise (Speicher) Verhängnis für diejenigen, die berufen threadDelay:

https://hackage.haskell.org/package/base-4.4.0.0/docs/src/GHC-Event-Manager.html#line-121

Wenn es noch ein Problem ist oder nicht, es ist schwer zu sagen. Allerdings kann man immer hoffen, dass ein "real life" -Zeitprogramm nicht zu viele Threads gleichzeitig auf threadDelay warten lassen muss. Ich für meinen Teil werde von nun an meine Verwendung von threadDelay im Auge behalten.

+0

WOW! Ich kann bestätigen, habe gerade mein Programm geändert, um 'MVar's zu verwenden und die neuen Zahlen sind: 221 MB ohne Gewinde und 282 MB Gewinde. Habe nie gedacht, dass 'threadDelay' ein Problem sein könnte. Vielen Dank. –