multithreading - Haskell/GHC por costes de memoria de hilo
memory (1)
Estoy tratando de entender lo caro que es un hilo (verde) en Haskell (GHC 7.10.1 en OS X 10.10.5) realmente. Soy consciente de que es súper barato en comparación con un subproceso de sistema operativo real, tanto para el uso de la memoria como para la CPU.
Correcto, entonces comencé a escribir un programa súper simple con subprocesos n (verdes) (usando la excelente biblioteca async ) y luego duerme cada subproceso durante m segundos.
Bueno, eso es bastante fácil:
$ 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]
y antes que nada, vamos a compilarlo y ejecutarlo:
$ 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
eso debería incluir 100k hilos y esperar 10 segundos en cada uno y luego imprimirnos algo de información:
$ 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
Tomó bastante tiempo (1m33.757s) dado que se supone que cada subproceso solo espera 10s, pero lo hemos construido sin hilos, lo suficientemente justo por ahora. En total, usamos 350 MB, eso no es tan malo, eso es 3.5 KB por hilo. Dado que el tamaño de pila inicial ( -ki es 1 KB ).
Correcto, pero ahora compilemos está en modo de subprocesos y veamos si podemos obtener algo más rápido:
$ 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, mucho más rápido, solo 12s ahora, mucho mejor. Desde el Monitor de actividad vi que usaba aproximadamente 4 subprocesos del sistema operativo para los 100k subprocesos verdes, lo que tiene sentido.
Sin embargo, 3657 MB de memoria total ! Eso es 10 veces más que la versión sin hilos utilizada ...
Hasta ahora, no hice ningún perfil usando -prof o -hy o así. Para investigar un poco más, hice algunos perfiles de pila ( -hy ) en ejecuciones separadas . El uso de la memoria no cambió en ninguno de los casos, los gráficos de perfiles del montón parecen interesantes (izquierda: sin hilos, derecha: hilos) pero no puedo encontrar la razón de la diferencia de 10 veces.
Al diferenciar la salida del perfil (archivos .prof ) tampoco puedo encontrar ninguna diferencia real.
Por lo tanto, mi pregunta: ¿De dónde proviene la diferencia de 10 veces en el uso de la memoria?
EDITAR : Solo para mencionarlo: La misma diferencia se aplica cuando el programa ni siquiera está compilado con soporte de perfiles. Entonces, el time ./PerTheadMem 100000 10 +RTS -sstderr ejecución time ./PerTheadMem 100000 10 +RTS -sstderr con ghc -rtsopts -threaded -fforce-recomp PerTheadMem.hs es de 3559 MB. Y con ghc -rtsopts -fforce-recomp PerTheadMem.hs es de 395 MB.
EDIT 2 : en Linux ( GHC 7.10.2 en Linux 3.13.0-32-generic #57-Ubuntu SMP, x86_64 ) sucede lo mismo: 460 MB sin subprocesos en 1: 28.538 y con hilos: 3483 MB es 12.604s. /usr/bin/time -v ... informa Maximum resident set size (kbytes): 413684 y Maximum resident set size (kbytes): 413684 Maximum resident set size (kbytes): 1645384 respectivamente.
EDIT 3 : también cambió el programa para usar forkIO directamente:
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]
Y no cambia nada: sin hilos: 152 MB, con hilos: 3308 MB.
En mi humilde opinión, el culpable es threadDelay . * threadDelay ** usa mucha memoria. Aquí hay un programa equivalente al tuyo que se comporta mejor con la memoria. Asegura que todos los subprocesos se ejecuten simultáneamente al tener un cálculo de larga ejecución.
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"
Y aquí están las estadísticas de tiempo:
$ 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
La residencia máxima es de alrededor de 1.5 kb por hilo. Jugué un poco con el número de subprocesos y la longitud de ejecución del cálculo. Dado que los hilos comienzan a hacer cosas inmediatamente después de forkIO, la creación de 100000 hilos en realidad lleva mucho tiempo. Pero los resultados se mantuvieron para 1000 hilos.
Aquí hay otro programa en el que threadDelay ha sido "factorizado", este no usa ninguna CPU y se puede ejecutar fácilmente con 100000 subprocesos:
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"
Y los resultados:
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
En mi i5, toma menos de un segundo crear los 100000 subprocesos y poner el mvar de "inicio". La residencia máxima es de alrededor de 778 bytes por subproceso, ¡no está nada mal!
Verificando la implementación de threadDelay, vemos que es efectivamente diferente para el caso de hilos y sin hilos:
https://hackage.haskell.org/package/base-4.8.1.0/docs/src/GHC.Conc.IO.html#threadDelay
Entonces aquí: https://hackage.haskell.org/package/base-4.8.1.0/docs/src/GHC.Event.TimerManager.html
que parece bastante inocente. Pero una versión anterior de base tiene una ortografía arcana de (memoria) doom para aquellos que invocan threadDelay:
https://hackage.haskell.org/package/base-4.4.0.0/docs/src/GHC-Event-Manager.html#line-121
Si todavía hay un problema o no, es difícil decirlo. Sin embargo, siempre se puede esperar que un programa concurrente "en la vida real" no tenga que tener demasiados hilos esperando en threadDelay al mismo tiempo. Por un lado voy a vigilar mi uso de threadDelay a partir de ahora.