Perché ci sono overhead che chiamano le funzioni Haskell da C?

Question

Ho notato un overhead significativo che chiama le funzioni Haskell in C, molto più grande del sovraccarico di una chiamata di funzione C nativa. Per distillare il problema alla sua essenza, ho scritto un programma che inizializza semplicemente il runtime di Haskell, esegue un ciclo che chiama una funzione vuota 100.000.000 di volte e restituisce.

Con la funzione inline, il programma impiega 0,003 s. Chiamare una funzione vuota scritta in C richiede 0,18 secondi. Chiamare una funzione vuota scritta in Haskell richiede 15.5 secondi. (Stranamente, se compilo il file Haskell vuoto separatamente prima del collegamento, ci vorranno ancora alcuni secondi. Sotto-domanda: perché è questo?)

Quindi sembra che ci sia un rallentamento di 100 volte tra chiamare una funzione C e chiamando una funzione Haskell. Qual è la ragione di questo, e c'è un modo per mitigare questo rallentamento?

Codice

EDIT: ho scoperto una versione di questo test nel NoFib benchmark suite, callback002. C'è uno nice blog post di Edward Z. Yang che menziona questo test nel contesto dello schedulatore GHC. Sto ancora cercando di ingannare questo post sul blog insieme alla risposta molto bella di Zeta. Non sono ancora convinto che non ci sia un modo per farlo più velocemente!

per compilare il "lento" versione Haskell, gestita

ghc -no-hs-main -O2 -optc-O3 test.c Test.hs -o test

Per compilare la versione "veloce" C, eseguire

ghc -no-hs-main -O2 -optc-O3 test.c test2.c TestDummy.hs -o test

test.c:

#include "HsFFI.h" 
extern void __stginit_Test(void); 

extern void test(); 

int main(int argc, char *argv[]) { 
    hs_init(&argc, &argv); 
    hs_add_root(__stginit_Test); 
    int i; 
    for (i = 0; i < 100000000; i++) { 
    test(); 
    } 
    hs_exit(); 
    return 0; 
} 

test2.c:

void test() { 
} 

Test.hs:

{-# LANGUAGE ForeignFunctionInterface #-} 

module Test where 

foreign export ccall test ::() 

test ::() 
test =() 

TestDummy.hs:

module Test where 

Answer 1

TL; DR: Motivo: RTS e STG chiamate. Soluzione: non chiamare funzioni banali Haskell da C.

---

Qual è la ragione di questo ...?

Disclaimer: Non ho mai chiamato Haskell da C. Ho familiarità con C e Haskell, ma raramente intrecciano entrambi, a meno che non stia scrivendo un wrapper. Ora che ho perso la mia credibilità, iniziamo questa avventura di benchmarking, disassemblaggio e altri orrendi ingegnosi.

Benchmarking con gprof

Un modo semplice per verificare ciò che sta mangiando tutte le risorse è quello di utilizzare gprof. Cambierà leggermente la linea di compilazione in modo che -pg sia usato sia dal compilatore che dal linker (nota: ho rinominato test.c in main.c e test2.c per testare.c):

$ ghc -no-hs-main -O2 -optc-O3 -optc-pg -optl-pg -fforce-recomp \ 
    main.c Test.hs -o test 
$ ./test 
$ gprof ./test 

Questo ci dà la seguente (piatta) profilo:

Flat profile: 

Each sample counts as 0.01 seconds. 
    % cumulative self    self  total   
time seconds seconds calls Ts/call Ts/call name  
16.85  2.15  2.15        scheduleWaitThread 
11.78  3.65  1.50        createStrictIOThread 
    7.66  4.62  0.98        createThread 
    6.68  5.47  0.85        allocate 
    5.66  6.19  0.72        traverseWeakPtrList 
    5.34  6.87  0.68        isAlive 
    4.12  7.40  0.53        newBoundTask 
    3.06  7.79  0.39        stg_ap_p_fast 
    2.36  8.09  0.30        stg_ap_v_info 
    1.96  8.34  0.25        stg_ap_0_fast 
    1.85  8.57  0.24        rts_checkSchedStatus 
    1.81  8.80  0.23        stg_PAP_apply 
    1.73  9.02  0.22        rts_apply 
    1.73  9.24  0.22        stg_enter_info 
    1.65  9.45  0.21        stg_stop_thread_info 
    1.61  9.66  0.21        test 
    1.49  9.85  0.19        stg_returnToStackTop 
    1.49  10.04  0.19        move_STACK 
    1.49  10.23  0.19        stg_ap_v_fast 
    1.41  10.41  0.18        rts_lock 
    1.18  10.56  0.15        boundTaskExiting 
    1.10  10.70  0.14        StgRun 
    0.98  10.82  0.13        rts_evalIO 
    0.94  10.94  0.12        stg_upd_frame_info 
    0.79  11.04  0.10        blockedThrowTo 
    0.67  11.13  0.09        StgReturn 
    0.63  11.21  0.08        createIOThread 
    0.63  11.29  0.08        stg_bh_upd_frame_info 
    0.63  11.37  0.08        c5KU_info 
    0.55  11.44  0.07        stg_stk_save_n 
    0.51  11.50  0.07        threadPaused 
    0.47  11.56  0.06        dirty_TSO 
    0.47  11.62  0.06        ghczmprim_GHCziCString_unpackCStringzh_info 
    0.47  11.68  0.06        stopHeapProfTimer 
    0.39  11.73  0.05        stg_threadFinished 
    0.39  11.78  0.05        allocGroup 
    0.39  11.83  0.05        base_GHCziTopHandler_runNonIO1_info 
    0.39  11.88  0.05        stg_catchzh 
    0.35  11.93  0.05        freeMyTask 
    0.35  11.97  0.05        rts_eval_ 
    0.31  12.01  0.04        awakenBlockedExceptionQueue 
    0.31  12.05  0.04        stg_ap_2_upd_info 
    0.27  12.09  0.04        s5q4_info 
    0.24  12.12  0.03        markStableTables 
    0.24  12.15  0.03        rts_getSchedStatus 
    0.24  12.18  0.03        s5q3_info 
    0.24  12.21  0.03        scavenge_stack 
    0.24  12.24  0.03        stg_ap_7_upd_info 
    0.24  12.27  0.03        stg_ap_n_fast 
    0.24  12.30  0.03        stg_gc_noregs 
    0.20  12.32  0.03        base_GHCziTopHandler_runIO1_info 
    0.20  12.35  0.03        stat_exit 
    0.16  12.37  0.02        GarbageCollect 
    0.16  12.39  0.02        dirty_STACK 
    0.16  12.41  0.02        freeGcThreads 
    0.16  12.43  0.02        rts_mkString 
    0.16  12.45  0.02        scavenge_capability_mut_lists 
    0.16  12.47  0.02        startProfTimer 
    0.16  12.49  0.02        stg_PAP_info 
    0.16  12.51  0.02        stg_ap_stk_p 
    0.16  12.53  0.02        stg_catch_info 
    0.16  12.55  0.02        stg_killMyself 
    0.16  12.57  0.02        stg_marked_upd_frame_info 
    0.12  12.58  0.02        interruptAllCapabilities 
    0.12  12.60  0.02        scheduleThreadOn 
    0.12  12.61  0.02        waitForReturnCapability 
    0.08  12.62  0.01        exitStorage 
    0.08  12.63  0.01        freeWSDeque 
    0.08  12.64  0.01        gcStableTables 
    0.08  12.65  0.01        resetTerminalSettings 
    0.08  12.66  0.01        resizeNurseriesEach 
    0.08  12.67  0.01        scavenge_loop 
    0.08  12.68  0.01        split_free_block 
    0.08  12.69  0.01        startHeapProfTimer 
    0.08  12.70  0.01        stg_MVAR_TSO_QUEUE_info 
    0.08  12.71  0.01        stg_forceIO_info 
    0.08  12.72  0.01        zero_static_object_list 
    0.04  12.73  0.01        frame_dummy 
    0.04  12.73  0.01        rts_evalLazyIO_ 
    0.00  12.73  0.00  1  0.00  0.00 stginit_export_Test_zdfstableZZC0ZZCmainZZCTestZZCtest 

Woah, questo è un gruppo di funzioni sempre chiamato. Come si confronta alla tua versione C?

$ ghc -no-hs-main -O2 -optc-O3 -optc-pg -optl-pg -fforce-recomp \ 
    main.c TestDummy.hs test.c -o test_c 
$ ./test_c 
$ gprof ./test_c 

Flat profile: 

Each sample counts as 0.01 seconds. 
    % cumulative self    self  total   
time seconds seconds calls Ts/call Ts/call name  
75.00  0.05  0.05        test 
25.00  0.06  0.02        frame_dummy 

Questo è un molto più semplice. Ma perché?

Cosa succede dietro?

Forse ti sei chiesto perché il test si è presentato anche nel profilo precedente. Beh, gprof si aggiunge un po 'in testa, come si può vedere con objdump:

$ objdump -D ./test_c | grep -A5 "<test>:" 

0000000000405630 <test>: 
    405630: 55      push %rbp 
    405631: 48 89 e5    mov %rsp,%rbp 
    405634: e8 f7 d4 ff ff   callq 402b30 <mcount@plt> 
    405639: 5d      pop %rbp 
    40563a: c3      retq 

Il richiamo della mcount viene aggiunto da gcc. Quindi per la parte successiva si desidera rimuovere le opzioni -pg. Controlliamo la smontato test di routine in C prima:

$ ghc -no-hs-main -O2 -optc-O3 -fforce-recomp \ 
    main.c TestDummy.hs test.c -o test_c 
$ objdump -D ./test_c | grep -A2 "<test>:" 

0000000000405510 <test>: 
    405510: f3 c3     repz retq 

Il repz retq è in realtà some optimisation magic, ma in questo caso si può pensare ad esso come un (quasi) ritorno no-op.

In che modo si confronta con la versione Haskell?

$ ghc -no-hs-main -O2 -optc-O3 -fforce-recomp \ 
    main.c Test.hs -o test_hs  
$ objdump -D ./Test.o | grep -A18 "<test>:" 

0000000000405520 <test>: 
    405520: 48 83 ec 18    sub $0x18,%rsp 
    405524: e8 f7 3a 05 00   callq 459020 <rts_lock> 
    405529: ba 58 24 6b 00   mov $0x6b2458,%edx 
    40552e: be 80 28 6b 00   mov $0x6b2880,%esi 
    405533: 48 89 c7    mov %rax,%rdi 
    405536: 48 89 04 24    mov %rax,(%rsp) 
    40553a: e8 51 36 05 00   callq 458b90 <rts_apply> 
    40553f: 48 8d 54 24 08   lea 0x8(%rsp),%rdx 
    405544: 48 89 c6    mov %rax,%rsi 
    405547: 48 89 e7    mov %rsp,%rdi 
    40554a: e8 01 39 05 00   callq 458e50 <rts_evalIO> 
    40554f: 48 8b 34 24    mov (%rsp),%rsi 
    405553: bf 64 57 48 00   mov $0x485764,%edi 
    405558: e8 23 3a 05 00   callq 458f80 <rts_checkSchedStatus> 
    40555d: 48 8b 3c 24    mov (%rsp),%rdi 
    405561: e8 0a 3b 05 00   callq 459070 <rts_unlock> 
    405566: 48 83 c4 18    add $0x18,%rsp 
    40556a: c3      retq 
    40556b: 0f 1f 44 00 00   nopl 0x0(%rax,%rax,1) 
    405570: d8 ce     fmul %st(6),%st 

questo sembra piuttosto diversa. In effetti, le funzioni RTS sembrano sospette. Diamo un'occhiata a loro:

• rts_checkSchedStatus controlla solo se lo stato è soddisfacente ed esce altrimenti. Il percorso Success non ha molto overhead, quindi questa funzione non è davvero il colpevole.
• rts_unlock and rts_lock in pratica reclamare e rilasciare un capability (una CPU virtuale). Chiamano newBoundTask e boundTaskExiting, che richiedono un po 'di tempo (vedere il profilo sopra).
• rts_apply chiamate allocate, una delle funzioni più utilizzate in tutto il programma (il che non è davvero sorprendente, dato che Haskell sta raccogliendo dati inutili).
• rts_evalIO infine crea il thread corrente e attende il suo completamento. Quindi possiamo stimare che il solo rts_evalIO impieghi circa il 27%.

Quindi abbiamo trovato tutte le funzioni che stanno prendendo tutto il tempo. STG e RTS si prendono tutto il credito per l'overhead di 150ns per chiamata.

... e c'è un modo per mitigare questo rallentamento?

Bene, il tuo test è praticamente un no-op. Lo chiami 100000000 volte, con un runtime totale di 15 secondi. Rispetto alla versione C, si tratta di un sovraccarico di ~ 149ns per chiamata.

La soluzione è abbastanza semplice: non utilizzare le funzioni Haskell nel tuo mondo C per compiti banali. Usa lo strumento giusto per la giusta situazione. Dopo tutto, non si utilizza la libreria GMP se è necessario aggiungere due numeri che sono garantiti per essere inferiore a 10.

Oltre a questa soluzione paradigmatica: no. L'assembly mostrato sopra è ciò che viene creato da GHC e non è possibile creare una variante senza chiamate RTS al momento.