2014-10-08 10 views
22

Spero di aver ridotto la mia domanda a un caso di test semplice e riproducibile. La sorgente (che è here) contiene 10 copie di un loop semplice identico. Ogni ciclo è nella forma:Perché le copie identiche dello stesso ciclo C nello stesso programma richiedono tempi significativamente diversi ma coerenti per l'esecuzione?

#define COUNT (1000 * 1000 * 1000) 
volatile uint64_t counter = 0; 

void loopN(void) { 
    for (int j = COUNT; j != 0; j--) { 
    uint64_t val = counter; 
    val = val + 1; 
    counter = val; 
    } 
    return; 
} 

Il 'volatili' della variabile è importante, in quanto costringe il valore di lettura e scrittura dalla memoria ad ogni iterazione. Ogni loop è allineato a 64 byte utilizzando '-falign-loop = 64' e produce montaggio identiche tranne che per l'offset al globale relativa:

400880:  48 8b 15 c1 07 20 00 mov 0x2007c1(%rip),%rdx # 601048 <counter> 
    400887:  48 83 c2 01    add $0x1,%rdx 
    40088b:  83 e8 01    sub $0x1,%eax 
    40088e:  48 89 15 b3 07 20 00 mov %rdx,0x2007b3(%rip) # 601048 <counter> 
    400895:  75 e9     jne 400880 <loop8+0x20> 

sto con Linux 3.11 su un i7-4470 Intel Haswell. Sto compilando il programma con GCC 4.8.1 e la linea di comando:

gcc -std=gnu99 -O3 -falign-loops=64 -Wall -Wextra same-function.c -o same-function 

Sono anche utilizzando attributo ((noinline)) nella fonte di rendere il montaggio più chiara, ma questo non è necessario per osservare il problema. Ho trovato le funzioni veloce e più lento con un ciclo shell:

for n in 0 1 2 3 4 5 6 7 8 9; 
do echo same-function ${n}:; 
/usr/bin/time -f "%e seconds" same-function ${n}; 
/usr/bin/time -f "%e seconds" same-function ${n}; 
/usr/bin/time -f "%e seconds" same-function ${n}; 
done 

Si produce risultati coerenti a circa 1% da un'analisi all'altra, con i numeri esatti del più veloce e funzioni lente variano a seconda del binario esatto Layout:

same-function 0: 
2.08 seconds 
2.04 seconds 
2.06 seconds 
same-function 1: 
2.12 seconds 
2.12 seconds 
2.12 seconds 
same-function 2: 
2.10 seconds 
2.14 seconds 
2.11 seconds 
same-function 3: 
2.04 seconds 
2.04 seconds 
2.05 seconds 
same-function 4: 
2.05 seconds 
2.00 seconds 
2.03 seconds 
same-function 5: 
2.07 seconds 
2.07 seconds 
1.98 seconds 
same-function 6: 
1.83 seconds 
1.83 seconds 
1.83 seconds 
same-function 7: 
1.95 seconds 
1.98 seconds 
1.95 seconds 
same-function 8: 
1.86 seconds 
1.88 seconds 
1.86 seconds 
same-function 9: 
2.04 seconds 
2.04 seconds 
2.02 seconds 

In questo caso, vediamo che che Loop2() è una delle più lente da eseguire e loop6() è uno dei più veloci, con una differenza poco più del 10%. Riconfermiamo questo testando solo questi due casi ripetutamente con un metodo diverso:

[email protected]$ N=2; for i in {1..10}; do perf stat same-function $N 2>&1 | grep GHz; done 
    7,180,104,866 cycles     # 3.391 GHz 
    7,169,930,711 cycles     # 3.391 GHz 
    7,150,190,394 cycles     # 3.391 GHz 
    7,188,959,096 cycles     # 3.391 GHz 
    7,177,272,608 cycles     # 3.391 GHz 
    7,093,246,955 cycles     # 3.391 GHz 
    7,210,636,865 cycles     # 3.391 GHz 
    7,239,838,211 cycles     # 3.391 GHz 
    7,172,716,779 cycles     # 3.391 GHz 
    7,223,252,964 cycles     # 3.391 GHz 

[email protected]$ N=6; for i in {1..10}; do perf stat same-function $N 2>&1 | grep GHz; done 
    6,234,770,361 cycles     # 3.391 GHz 
    6,199,096,296 cycles     # 3.391 GHz 
    6,213,348,126 cycles     # 3.391 GHz 
    6,217,971,263 cycles     # 3.391 GHz 
    6,224,779,686 cycles     # 3.391 GHz 
    6,194,117,897 cycles     # 3.391 GHz 
    6,225,259,274 cycles     # 3.391 GHz 
    6,244,391,509 cycles     # 3.391 GHz 
    6,189,972,381 cycles     # 3.391 GHz 
    6,205,556,306 cycles     # 3.391 GHz 

Considerando questo confermato, rileggiamo ogni parola in ogni Intel manuale di architettura mai scritto, setacciare ogni pagina su tutto il web che cita le parole "computer" o "programmazione" e meditano isolatamente su una montagna per 6 anni. Non riuscendo a raggiungere alcun tipo di illuminazione, arriviamo alla civiltà, ci radiamo la barba, facciamo il bagno e chiediamo agli esperti di StackOverflow:

Cosa può accadere qui?

Modifica: Con l'aiuto di Benjamin (vedere la risposta di seguito) Ho trovato un altro succinct test case. Sono 20 linee di montaggio indipendenti. Il passaggio da SUB a SBB causa una differenza del 15% nelle prestazioni anche se il risultato rimane lo stesso e viene eseguito lo stesso numero di istruzioni. Spiegazioni? Penso che mi sto avvicinando a uno.

; Minimal example, see also http://stackoverflow.com/q/26266953/3766665 
; To build (Linux): 
; nasm -felf64 func.asm 
; ld func.o 
; Then run: 
; perf stat -r10 ./a.out 
; On Haswell and Sandy Bridge, observed runtime varies 
; ~15% depending on whether sub or sbb is used in the loop 
section .text 
global _start 
_start: 
    push qword 0h  ; put counter variable on stack 
    jmp loop   ; jump to function 
align 64    ; function alignment. 
loop: 
    mov rcx, 1000000000 
align 64    ; loop alignment. 
l: 
    mov rax, [rsp] 
    add rax, 1h 
    mov [rsp], rax 
; sbb rcx, 1h   ; which is faster: sbb or sub? 
    sub rcx, 1h   ; switch, time it, and find out 
    jne l    ; (rot13 spoiler: foo vf snfgre ol 15%) 
fin:     ; If that was too easy, explain why. 
    mov eax, 60 
    xor edi, edi  ; End of program. Exit with code 0 
    syscall 
+2

Come stai contabili per processi in background che interrompono il vostro programma? (Non ho molta familiarità con Linux, ma su Windows questo è un grosso problema quando si prova a utilizzare il codice semplice ma a lunga esecuzione.) Quando il thread va in sospensione, trascorre un intervallo di tempo sconosciuto non in esecuzione quando il timer è ancora - probabile - ticchettio. – xxbbcc

+1

Questo non sembra essere un problema con contesa del processore. Ciò potrebbe spiegare la variazione dei tempi tra le esecuzioni per lo stesso N, ma non tiene conto della differenza consistente e statisticamente significativa dei runtime per diversi N. –

+3

Qual è l'allineamento degli indirizzi per, ad esempio, 'loop6' e' loop1 '- Sono entrambi allineati a 32 byte? Hanno lo stesso allineamento generale? –

risposta

1

Alcuni anni fa, ti avrei detto di verificare la presenza di eventuali differenze nello stato interno della CPU quando si arriva a uno qualsiasi di questi cicli; poiché questo era noto per avere un profondo effetto sulla capacità del processo di previsione Out of Order (o qualcosa del genere). Ad esempio, le prestazioni dello stesso loop potrebbero cambiare fino a qualcosa come il 15-20% a seconda di ciò che la CPU stava facendo prima di entrare nel loop e il solo fatto di saltare da due punti diversi potrebbe essere sufficiente per cambiare l'esecuzione velocità.

Nel tuo caso, è abbastanza da testare.Tutto quello che devi fare è cambiare l'ordine delle istruzioni nel blocco IF; per esempio sostituendo il seguente:

switch (firstLetter) { 
    case '0': loop0(); break; 
    case '1': loop1(); break; 
    case '2': loop2(); break; 
    case '3': loop3(); break; 
    case '4': loop4(); break; 
    case '5': loop5(); break; 
    case '6': loop6(); break; 
    case '7': loop7(); break; 
    case '8': loop8(); break; 
    case '9': loop9(); break; 
    default: goto die_usage; 
    } 

con:

switch (firstLetter) { 
    case '9': loop9(); break; 
    case '8': loop8(); break; 
    case '7': loop7(); break; 
    case '6': loop6(); break; 
    case '5': loop5(); break; 
    case '4': loop4(); break; 
    case '3': loop3(); break; 
    case '2': loop2(); break; 
    case '1': loop1(); break; 
    case '0': loop0(); break; 
    default: goto die_usage; 
    } 

o con qualsiasi ordine casuale. Naturalmente, dovresti controllare il codice assembly generato per assicurarti che l'ordine delle istruzioni non sia stato riordinato dal compilatore.

Inoltre, poiché i loop sono all'interno delle singole funzioni; dovresti anche assicurarti che queste funzioni siano allineate su 64 confini.

+0

Non sono sicuro di aver capito la tua risposta. Se si suggerisce che la posizione da cui si verifica la chiamata determina la velocità della funzione, non so quale potrebbe essere il meccanismo per questo. Ma ho cambiato l'ordine a quello che hai proposto, e ho scoperto che la posizione della funzione all'interno dell'istruzione switch non influenza la velocità con cui viene eseguita. Cioè, la velocità sembra essere una proprietà della funzione. Per riconfermare, ho anche modificato l'assembly generato per scambiare le chiamate con le funzioni "più veloci" e "più lente" dell'originale, e ho scoperto che rimanevano tali. –

+0

Questa è stata una mia idea. Alcuni anni fa, il meccanismo di OOO era molto imprevedibile. Nel tuo caso, un'altra possibilità sarebbe la differenza di allineamento per ogni funzione. È anche possibile controllare di sostituire le funzioni con le istruzioni goto. – SylvainL

+0

* È anche possibile verificare la sostituzione delle funzioni con le istruzioni goto. * Ottengo differenze temporali simili quando consento che le funzioni siano in linea, che a mio avviso dovrebbero essere uguali (o più definitive) rispetto al passaggio a un goto. Cambia quale 'funzione' è veloce, ma non rimuove il problema. Nell'esempio non l'ho fatto perché pensavo di avere tutto nelle principali() cose complicate. –

9

Osservando l'output perf perf stat, vedrete che non è il numero di istruzioni che varia ma il numero di cicli in stallo.

Guardando il disassemblaggio, ho trovato due cose:

  1. L'offset per la variabile contatore varia tra le funzioni. Rendere il contatore locale a ciascuna funzione non ha però comportato il decadimento del comportamento.
  2. Le funzioni non sono posizionate su limiti di 64 byte, pertanto potrebbero coprire una quantità diversa di righe della cache. Compilare con -falign-functions = 64 ha fatto sparire le differenze quasi completamente.

Fare il test con le suddette modifiche sulla mia macchina poi cede:

for f in $(seq 7); do perf stat -e cycles -r3 ./same-function $f 2>&1; done|grep cycles 6,070,933,420 cycles (+- 0.11%) 6,052,771,142 cycles (+- 0.06%) 6,099,676,333 cycles (+- 0.07%) 6,092,962,697 cycles (+- 0.16%) 6,151,861,993 cycles (+- 0.69%) 6,074,323,033 cycles (+- 0.36%) 6,174,434,653 cycles (+- 0.65%)

non so di più sulla natura delle bancarelle che hai trovato, però.

EDIT: Ho fatto contatore dell'utente volatile ciascuna funzione, testato diverse compilazioni sul mio I7-3537U e trovarono `-falign-loop = 64' effettivamente essere più lenta:

$ gcc -std=gnu99 -O3 -Wall -Wextra same-function.c -o same-function 
$ gcc -falign-loops=64 -std=gnu99 -O3 -Wall -Wextra same-function.c -o same-function-l64 
$ gcc -falign-functions=64 -std=gnu99 -O3 -Wall -Wextra same-function.c -o same-function-f64 
$ for prog in same-function{,-l64,-f64}; do echo $prog; for f in $(seq 7); do perf stat -e cycles -r10 ./$prog $f 2>&1; done|grep cycl; done 
same-function 
    6,079,966,292  cycles      (+- 0.19%) 
    7,419,053,569  cycles      (+- 0.07%) 
    6,136,061,105  cycles      (+- 0.27%) 
    7,282,434,896  cycles      (+- 0.74%) 
    6,104,866,406  cycles      (+- 0.16%) 
    7,342,985,942  cycles      (+- 0.52%) 
    6,208,373,040  cycles      (+- 0.50%) 
same-function-l64 
    7,336,838,175  cycles      (+- 0.46%) 
    7,358,913,923  cycles      (+- 0.52%) 
    7,412,570,515  cycles      (+- 0.38%) 
    7,435,048,756  cycles      (+- 0.10%) 
    7,404,834,458  cycles      (+- 0.34%) 
    7,291,095,582  cycles      (+- 0.99%) 
    7,312,052,598  cycles      (+- 0.95%) 
same-function-f64 
    6,103,059,996  cycles      (+- 0.12%) 
    6,116,601,533  cycles      (+- 0.29%) 
    6,120,841,824  cycles      (+- 0.18%) 
    6,114,278,098  cycles      (+- 0.09%) 
    6,105,938,586  cycles      (+- 0.14%) 
    6,101,672,717  cycles      (+- 0.19%) 
    6,121,339,944  cycles      (+- 0.11%) 

Maggiori dettagli su align-loops vs align-funzioni:

$ for prog in same-function{-l64,-f64}; do sudo perf stat -d -r10 ./$prog 0; done 

Performance counter stats for './same-function-l64 0' (10 runs): 

     2396.608194  task-clock:HG (msec)  # 1.001 CPUs utilized   (+- 0.64%) 
       56  context-switches:HG  # 0.024 K/sec     (+- 5.51%) 
       1  cpu-migrations:HG   # 0.000 K/sec     (+- 74.78%) 
       46  page-faults:HG   # 0.019 K/sec     (+- 0.63%) 
    7,331,450,530  cycles:HG     # 3.059 GHz      (+- 0.51%) [85.68%] 
    5,332,248,218  stalled-cycles-frontend:HG # 72.73% frontend cycles idle  (+- 0.71%) [71.42%] 
    <not supported>  stalled-cycles-backend:HG 
    5,000,800,933  instructions:HG   # 0.68 insns per cycle 
                # 1.07 stalled cycles per insn (+- 0.04%) [85.73%] 
    1,000,446,303  branches:HG    # 417.443 M/sec     (+- 0.04%) [85.75%] 
      8,461  branch-misses:HG   # 0.00% of all branches   (+- 6.05%) [85.76%] 
    <not supported>  L1-dcache-loads:HG 
      45,593  L1-dcache-load-misses:HG # 0.00% of all L1-dcache hits (+- 3.61%) [85.77%] 
      6,148  LLC-loads:HG    # 0.003 M/sec     (+- 8.80%) [71.36%] 
    <not supported>  LLC-load-misses:HG 

     2.394456699 seconds time elapsed           (+- 0.64%) 


Performance counter stats for './same-function-f64 0' (10 runs): 

     1998.936383  task-clock:HG (msec)  # 1.001 CPUs utilized   (+- 0.61%) 
       60  context-switches:HG  # 0.030 K/sec     (+- 17.77%) 
       1  cpu-migrations:HG   # 0.001 K/sec     (+- 47.86%) 
       46  page-faults:HG   # 0.023 K/sec     (+- 0.68%) 
    6,107,877,836  cycles:HG     # 3.056 GHz      (+- 0.34%) [85.63%] 
    4,112,602,649  stalled-cycles-frontend:HG # 67.33% frontend cycles idle  (+- 0.52%) [71.41%] 
    <not supported>  stalled-cycles-backend:HG 
    5,000,910,172  instructions:HG   # 0.82 insns per cycle 
                # 0.82 stalled cycles per insn (+- 0.01%) [85.72%] 
    1,000,423,026  branches:HG    # 500.478 M/sec     (+- 0.02%) [85.77%] 
      10,660  branch-misses:HG   # 0.00% of all branches   (+- 13.23%) [85.80%] 
    <not supported>  L1-dcache-loads:HG 
      47,492  L1-dcache-load-misses:HG # 0.00% of all L1-dcache hits (+- 14.82%) [85.80%] 
      11,719  LLC-loads:HG    # 0.006 M/sec     (+- 42.44%) [71.28%] 
    <not supported>  LLC-load-misses:HG 

     1.997319759 seconds time elapsed           (+- 0.62%) 

Entrambi gli eseguibili hanno un numero molto basso di istruzioni/ciclo, probabilmente a causa della natura minimalista del ciclo e la pressione di memoria che sta infliggendo, ma non ho idea del perché uno sia peggio dell'altro.

Ho anche provato qualcosa sulla falsariga di

$ for prog in same-function{-l64,-f64}; do sudo perf stat -eL1-{d,i}cache-load-misses,L1-dcache-store-misses,cs,cycles,instructions -r10 ./$prog 0; done 

e

$ sudo perf record -F25000 -e'{cycles:pp,stalled-cycles-frontend}' ./same-function-l64 0 
[ perf record: Woken up 28 times to write data ] 
[ perf record: Captured and wrote 6.771 MB perf.data (~295841 samples) ] 
$ sudo perf report --group -Sloop0 -n --show-total-period --stdio 
$ sudo perf annotate --group -sloop0 --stdio 

Ma senza alcun successo sulla ricerca del colpevole. Eppure, ho sentito che potrebbe essere utile per annotare giù qui per voi in ogni caso ...

Edit 2: Qui è la mia patch stessa funzione.c:

$ git diff -u -U0 
diff --git a/same-function.c b/same-function.c 
index f78449e..78a5772 100644 
--- a/same-function.c 
+++ b/same-function.c 
@@ -20 +20 @@ done 
-volatile uint64_t counter = 0; 
+//volatile uint64_t counter = 0; 
@@ -22,0 +23 @@ COMPILER_NO_INLINE void loop0(void) { 
+volatile uint64_t counter = 0; 
@@ -31,0 +33 @@ COMPILER_NO_INLINE void loop1(void) { 
+volatile uint64_t counter = 0; 
@@ -40,0 +43 @@ COMPILER_NO_INLINE void loop2(void) { 
+volatile uint64_t counter = 0; 
@@ -49,0 +53 @@ COMPILER_NO_INLINE void loop3(void) { 
+volatile uint64_t counter = 0; 
@@ -58,0 +63 @@ COMPILER_NO_INLINE void loop4(void) { 
+volatile uint64_t counter = 0; 
@@ -67,0 +73 @@ COMPILER_NO_INLINE void loop5(void) { 
+volatile uint64_t counter = 0; 
@@ -76,0 +83 @@ COMPILER_NO_INLINE void loop6(void) { 
+volatile uint64_t counter = 0; 
@@ -85,0 +93 @@ COMPILER_NO_INLINE void loop7(void) { 
+volatile uint64_t counter = 0; 
@@ -94,0 +103 @@ COMPILER_NO_INLINE void loop8(void) { 
+volatile uint64_t counter = 0; 
@@ -103,0 +113 @@ COMPILER_NO_INLINE void loop9(void) { 
+volatile uint64_t counter = 0; 
@@ -135 +145 @@ int main(int argc, char** argv) { 
-} 
\ No newline at end of file 
+} 

Edit 3: La stessa cosa con esempio ancora più minimale:

; Minimal example, see also http://stackoverflow.com/q/26266953/3766665 
; To build (Linux): 
; nasm -felf64 func.asm 
; ld func.o 
; Then run: 
; perf stat -r10 ./a.out 
; Runtime varies ~10% depending on whether 
section .text 
global _start 
_start: 
    push qword 0h  ; put counter variable on stack 
    jmp loop   ; jump to function 
;align 64    ; function alignment. Try commenting this 
loop: 
    mov rcx, 1000000000 
;align 64    ; loop alignment. Try commenting this 
l: 
    mov rax, [rsp] 
    add rax, 1h 
    mov [rsp], rax 
    sub rcx, 1h 
    jne l 
fin:     ; End of program. Exit with code 0 
    mov eax, 60 
    xor edi, edi 
    syscall 

Stesso effetto qui. Interessante.

Cheers, Benjamin

+0

I processori moderni sono animali non deterministici complessi. Quella che si sta testando ha cache L2 e L3, 4 core, 8 thread, previsione ramo e esecuzione fuori servizio. Le bancarelle provengono dalla miriade di interazioni tra tutti questi aspetti della CPU. Un errore di cache, porta ad un accesso alla memoria, porta ad un possibile switch di thread, porta ad un flushing della previsione dei branch, ecc. Quando si guarda lo schema dettagliato della CPU è sorprendente che la cosa funzioni anche e fornisca risposte coerenti La maggior parte delle volte. Non posso aspettarmi che anche il tempo tham sia lo stesso. – CyberFonic

+0

Ho toccato brevemente questo in un primo commento. Mentre l'allineamento delle funzioni fa la differenza, penso che sia solo perché influenza l'indirizzo del loop all'interno. Se compilo con "gcc -std = gnu99 -O3 -falign-functions = 64 -falign-loops = 64 -Wall -Wextra same-function.c -o same-function", vedo numeri da 6.271.509.852 a 7.191.368.933, con un corrispondente grado di precisione. Lo vedi anche quando aggiungi back -falign-loops = 64? Rimane costante quando provi diversi valori di loop di allineamento? Il tuo comando loop e perf è particolarmente elegante - grazie per averlo dimostrato! –

+1

@Nathan, ho preso le istruzioni di compilazione dal commento in cima a same-function.c, non ho notato che non conteneva i -falign-loops = 64 che hai suggerito e poi ho controllato l'allineamento con "eu-readelf - s same-function | grep loop "e" objdump -d same-function ". Mi stavo solo chiedendo che il codice non fosse allineato su 64 byte e se forse mancavano le cache di istruzioni potrebbe essere un problema, quindi ho provato le funzioni -falign. Cercherò di rispondere alle tue altre domande la sera, visto che sono lontano dalla mia macchina in questo momento. Saluti! – bking

Problemi correlati