実行時間の計測（Ｃ言語）

実行時間について教えてください。
実行時間について不可思議な現象が起きたので疑問に思いました。

Ｃ言語においてfor文の２億回ループする場合の実行時間を計測し、計測する内容を変えます。
以下のプログラムのように、時間を計測します。
--------------------
　　　　　　　・
　　　　　　　・
gettimeofday(&t0, NULL);

　（計測したい処理）

gettimeofday(&t1, NULL);

　　　　　　　・
　　　　　　　・
---------------------
（計測したい処理）に以下のようなプログラムを入れ時間を計測しました。
以下、（計測したい処理）　　→　それにかかった実行時間

＜実行結果　書式（計測したい処理）　→　計測された時間　＞
(1)for ( i = 0; i < 2000000000; i++);　　　　　　　　　→　　5.412432 sec
(2)for ( i = 0; i < 2000000000; i++, a++);　　　　 　→　　5.401164 sec
(3)for ( i = 0; i < 2000000000; i++, a++,a++); 　　→　　9.340447 sec
(4)for ( i = 0; i < 2000000000; i++, a++,a++,a++); 　　→　　13.985456 sec

この結果を受けての疑問（１）
(2)～(4)までは、加算する回数(a++)が２倍、３倍と増えたため、線形的に実行時間が増えるという理屈で納得できるのですが、
(1)～(2)について、加算する回数(a++)が増えているのに、なぜ実行時間が(1)と(2)では変わらないのか。
アセンブラに直すと、確かに加算回数は増えているはずです。

＜実行結果　書式（計測したい処理）　→　計測された時間　＞
(5)for ( i = 0; i < 2000000000; i++);　　　　　　　　　　　→　　5.412432 sec
(6)for ( i = 0; i < 2000000000; i++, a++);　　　　 　　　→　　5.401164 sec
(7)for ( i = 0; i < 2000000000; i++, a++,b++); 　　　　→　　4.019215 sec
(8)for ( i = 0; i < 2000000000; i++, a++,b++,c++); 　　→ 　4.008310 sec
　
実行結果を受けての疑問（２）
なぜ、(6)～(7)では、加算される回数は増えているにも関わらず、
(5)より実行時間は短くなっているのか。

（(3)と(7)の時間差があることについは、対象となるレジスタが違うため、並行処理をしていると推察できることはわかります。今回は(5)～(8)にかけて、なぜ実行時間が短くなるのかという質問です。）

＜前提＞
・前提として、プログラム内容に間違いはない。
・バックグラウンドで動いているプログラムの影響は受けていないとします。
（何度も実行して確認しているので常にこのような結果が得られました。）

疑問１、２について、推測できる理由を教えてください。


<環境>
・Windows7 Corei5　上で　VMwareによってUbuntuで実行しています。（ＶＭwareのコア数の設定は１）
・メモリはWindowsOS、VMwareによる設定共に２ＧＢ

<ソース>

#include <stdio.h>
#include <sys/time.h> // gettimeofday

int main()
{

struct timeval t0, t1;
long l;
long i;
long h;
long j;
long k;
i = 0;
h = 0;
l = 0;
j = 0;
k = 0;
gettimeofday(&t0, NULL);

for ( i = 0; i < 2000000000; i++,l++,h++,j++);　/*この部分の加算を変更して計測しています。*/

gettimeofday(&t1, NULL);
printf("i = %ld, l = %ld, h=%ld \n",i,l,h);

t1.tv_sec -= t0.tv_sec;
if (t1.tv_usec < t0.tv_usec) {
t1.tv_sec -= 1;
t1.tv_usec += 1000000 - t0.tv_usec;
} else {
t1.tv_usec -= t0.tv_usec;
}
printf("%d.%06d sec\n", t1.tv_sec, t1.tv_usec);

}


わかる方、回答を何卒お願いします。
（解答に必要な条件が足りないのでしたら、教えてください。すぐに追記します。）

No.9 回答者： davidfox 回答日時： 2013/02/24 11:57

(1)と(2)の違いのみ：

Pentium II 256MHz　で試しました。

(1)より(2)が若干早くなりました。
(1) 54.862378 sec
(2) 53.012287 sec

そこで、nop を幾つか挟んでみた処...
for ( i = 0; i < 2000000000; i++) {
__asm__("nop");
__asm__("nop");
}

かなり早くなりました。
(1') 46.948590 sec ... nop x 2 挿入

パイプライン処理は詳しくありませんが、nop の挿入数でかなり変わるので、その構造にマッチしているか、していないかの違いではないかと思います。

for 部のアセンブリコードは以下でした（2つ混在させた為、ラベルが異なる）。

(2)のコード
movl $0, -24(%ebp)
.p2align 2
.L4:
cmpl $1999999999, -24(%ebp)
jle .L6
jmp .L8
.p2align 2
.L6:
leal -24(%ebp), %eax
incl (%eax)
leal -20(%ebp), %eax
incl (%eax)
jmp .L4
.p2align 2

(1')のコード
.L21:
nop
movl $0, -24(%ebp)
.p2align 2
.L27:
cmpl $1999999999, -24(%ebp)
jle .L30
jmp .L8
.p2align 2
.L30:
#APP
nop
nop
#NO_APP
leal -24(%ebp), %eax
incl (%eax)
jmp .L27
.p2align 2
.L8:

No.8 回答者： ulisrt 回答日時： 2013/02/24 02:31

> しかし、（１）～（２）間だけがどうしても説明ができない…。

おや?
Celeronの話ですよね。

読み書きするメモリアドレスの同異が影響していると仮定するなら、(1),(2)間が(2)以降より時間の増え方が鈍いのは筋が通るのではないでしょうか。i++ と a++ ではアドレスが違うので。

他のCPUの(5)(6)などは、これだけでは説明がつかないですが。
i は分岐予測に関わってくるので他の変数と扱いが変わってくるのでは、くらいの想像しか思いつきません。

この回答へのお礼

申し訳ありません。
少し勘違いをしていました。
おっしゃる通りです（笑）

（１）→（２）は説明がつきますね。

ありがとうございます。

Celeronは（１）→（４）（５）→　（８）すべて説明がつきますね。
問題はコアが多い場合ですね。

お礼日時：2013/02/24 03:16

No.7 ベストアンサー 回答者： ulisrt 回答日時： 2013/02/23 18:34

書き忘れました。

私が試したのは 64bit の Ubuntu 12.04 です。

それから前言を撤回します。仮想環境でなくても1,2間で処理時間が増えない場合はありますね。

別のPCも含めて、再度試してみました。
--------------------------
Ubuntu 12.04 (64bit) Core i7-3720QM 2.6 GHz (8 core)
(1) 3.431967 sec
(2) 3.943790 sec
(3) 6.874282 sec
(4) 10.425479 sec
(5) 3.392887 sec
(6) 3.918412 sec
(7) 4.458465 sec
(8) 3.947680 sec
--------------------------
Vine 6.0 (32bit) Core2 Duo T7250 2.0 GHz (2 core)
(1) 7.082609 sec
(2) 7.086212 sec
(3) 12.156981 sec
(4) 18.270035 sec
(5) 7.082886 sec
(6) 7.069174 sec
(7) 7.393213 sec
(8) 9.099289 sec
--------------------------
Vine 3.2 (32bit) Mobile Celeron 1.8 GHz (1 core)
(1) 4.712198 sec
(2) 6.769757 sec
(3) 13.794606 sec
(4) 21.499377 sec
(5) 4.516656 sec
(6) 6.848446 sec
(7) 9.207516 sec
(8) 11.300254 sec
--------------------------

全て native install です。また最適化はしていないので、加算命令（64bitはaddq, 32bitはaddl）もCのコードと素直に対応しています。やはり古いCeleronは、他よりも処理が時間に反映されている気がしますね。

同じメモリへの加算より、違うメモリへの加算の方が時間の増え方が鈍いです。キャッシュには余裕で入りきるサイズでしょうから、パイプラインが影響している気がしますが。

他の皆さんも言われている通り、要因が多すぎて確かなことは不明です。

この回答へのお礼

ありがとうございます。
いろいろと実験してくださったんですね。

私も、Corei3にUbunutu12.04をnative installしてみました。
やはり、結果はulist様と同様もののでした。
（私も最適化していません。）


>同じメモリへの加算より、違うメモリへの加算の方が時間の増え方が鈍いです

違うメモリへの加算(（５）～（８）)の実行時間が増えにくいのは、
ほぼパイプラインの影響でしょうね。

（１）（２）間もしｋは、（５）（６）間で基本的に、実行時間があまり増えない理由が
いろいろ調べているのですが、まだ分からないです。
Celeronの結果を見ると、
（２）～（４）では線形的に時間が増えていっていて、
つじつまが合いますよね。
しかし、（１）～（２）間だけがどうしても説明ができない…。

どこに理由があるのでしょうね。

お礼日時：2013/02/23 19:28

No.6 回答者： wormhole 回答日時： 2013/02/23 10:29

>今回のプログラムですと、空ループはないと思います。

>なぜなら、後でa++;　i++;等、２億回ループしたのですが、
>その変数の中身を表示しているからです。

コンパイラや最適化オプションにもよりますが単純に2億回 a++や i++をやってるだけならループ自体省略して a += 2000000000 などのようにコンパイルされる場合もあります。

この回答へのお礼

なるほど！
確かにそれでしたら、ループ処理はいらなくなりますね！！

（５）（６）の実行時間より、（７）（８）の実行時間が短くなったのは、
そういう理由もあるんでしょうか。

また、gcc -O0　とすれば、これらの最適化も一切行わなくなると思うので、
まだ実行時間が短くなる理由がしっくりきません。。。

とても奥が深いです。

お礼日時：2013/02/23 12:40

No.5 回答者： tadys 回答日時： 2013/02/23 09:38

最近のパソコン用のCPUでは、アセンブラのコードとCPU内の実行が１対１に対応しているわけではないので、コードから実行時間が推測できない場合も有ります。

同時に実行して問題が起きないコードは同時に実行される事が有ります。
例えば、for ( i = 0; i < 2000000000; i++, a++);　の場合、 i++と a++が同時に実行されている事は予想の範囲内です。
i++, a++,b++,c++の場合も同様です。
http://d.hatena.ne.jp/hyoshiok/20070916#p1

for ( i = 0; i < 2000000000; i++, a++,a++); の場合、最初のa++と２番目のa++は同時には実行できないんでしょう。
頭の良いコンパイラなら、これを a+=2 に置き換えてしまうかもしれません。
最適化レベルを上げればループそのものを省略してしまうだろうけど。

この回答への補足

早速のご回答ありがとうございます。

（２）～（４）については、a++;の個数分、線形的に実行時間が増加しています。
それ以降も、a++;の個数分だけ増えていくんですよね。
i++; a++;　だけの場合、同時に実行できるので、なんとなく納得はできる気がしてきました。
ありがとうございます。

しかし、
（５）と（７）を比較すると理解が困難です。
（５）より（７）のほうが実行時間が短いのはなぜなんでしょうか。
並列実行されているとしたら、（５）と（７）が同程度の実行時間になる気がするのですが…。

何か追加でアドバイスがありましたら
ご教授お願いします。

補足日時：2013/02/23 10:05

No.4 回答者： TXV12003 回答日時： 2013/02/23 08:12

初めに言っておきますが、私はその環境についての知識はゼロです。

コンパイラの最適化で、空ループが無視されていませんか？


対策としては下記のように、アセンブラでＮＯＰ命令を入れるとどうでしょうか？

for ( i = 0; i < 2000000000; i++)
｛
　　　__asm__("nop"); 　　//←すみません、この書き方が正しいかどうかも知りません（笑）
}
　　　

この回答へのお礼

回答ありがとうございます。

今回のプログラムですと、空ループはないと思います。
なぜなら、後でa++;　i++;等、２億回ループしたのですが、
その変数の中身を表示しているからです。

NOP命令についは、初めて知りました。
あまり、アセンブラについはあまり詳しくないので、
アドバイスを元に、アセンブラを勉強してＮＯＰ命令など
試してみたいと思います。
また、報告します。

お礼日時：2013/02/23 10:20

No.3 回答者： ulisrt 回答日時： 2013/02/23 07:47

同じプログラムを、Ubuntu 12.04 を native install した環境(Core i7-3720QM)で実行してみました。

(1) 3.393335 sec
(2) 4.110268 sec
(3) 6.875924 sec
(4) 10.391332 sec

一応、1と2の間で増加傾向が見られます。
やはり仮想環境での評価は少し問題があるのでは？

この回答への補足

回答ありがとうございます。

ＶＭ上だからってことですか・・・。
一度、native installで実行してみます。

また、実行結果を踏まえて、ご報告させていただきたいと思います。
ちなみに、（５）～（８）の結果についてはいかがでしょうか。

補足日時：2013/02/23 10:07

この回答へのお礼

追加です。

ulist様の（１）～（４）の実行結果なのですが、
処理時間が線形的に増えない理由として、
どのようなことが考えられると思いますか？

あらためて、結果を見ていて、疑問に思ったので、
ulist様のご意見も聞いてみたいです！

お礼日時：2013/02/23 10:16

No.2 回答者： kmee 回答日時： 2013/02/23 06:39

> アセンブラに直すと、確かに加算回数は増えているはずです。

実際に、アセンブリにコンパイルして確認したらどうです？
gccなら-Sでできます。

あと、コンパイル時のオプション、特に最適化関係はどうなってますか？
さすがに、ループを省略する様なのは、設定してない様には見えますが



最近のPCでは、一つのプログラムを全力で実行するようなことはほとんどありません。
キャッシュだの並列化だの、不確定な要素もおおいです。

この回答への補足

アセンブラコードも確認しまして、
gcc -S　で内容を見てみました。
すると、やはり加算命令がふえているだけの単純なものでした。

a++; →　addl $1 16($ep)
a++; b++;　→　addl $1 16($ep)　　　addl $1 24($ep)　　/*アドレス番号は適当です*/

なので、アセンブラを見る限りだけだと、
加算命令回数が増える（当初の予想通り）んですよね。
やはり不可思議です・・・。

また、コンパイルオプションについてですが、
gcc -O0　とし、最適化をせずに実行をしても結果は変わりませんでした。


不確定要素は確かにそうですね。
・ＯＳのジョブ処理優先順位
・キャッシュ
・最適化
人の手で制御できないものも考えられますね。

（５）→（７）となる理由はこれらの内容でどう説明したらよろしいでしょうか。

補足日時：2013/02/23 10:14

No.1 回答者： yama1718 回答日時： 2013/02/23 03:02

VMwareのエミュレータの仮想ＣＰＵはプログラムコードが実行できれは良いのであって、動作速度やクロック数まで忠実に再現しているとは思えません。

できるだけ効率が良くなるように最適化されているでしょうね。
それにエミュレータはホストのＣＰＵの処理能力によって仮想環境内の時間進行と現実世界の時間進行に差が出ないように足かせを入れて調整しています。
更にホストはCore i5で4コア(種類によっては2コア)となるともっとややこしくなりますね。

そもそもプログラムコードから各命令のクロック数とＣＰＵの動作周波数から実行速度を正確に計算できるのは旧世代の８ビットＣＰＵぐらいまでか、組み込み系などで特別に設計されたマイコンだけだと思います。

この回答へのお礼

回答ありがとうございます。

仮想環境が問題なのかもしれませんね。
native installして試してみます。
また、コアが多いとそれはそれで面倒なのかもしれません。

また、実験して報告させていただきます。

お礼日時：2013/02/23 10:23