multithreading - Haskell/GHC por costes de memoria de hilo

memory

Question

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.

Answer 1

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.