プログラマ専用SNS ミクプラ

どうしてもわからないことがあり、質問させていただきます。
_sleep(1)を1000回実行する以下のサンプルプログラムを作成し、実行すると
pcによって出力される結果が異なります。
出力結果を<out1>,<out2>としてsample programの下に示します。
<out1>では毎回_sleep()関数が機能しているようですが<out2>では
毎回は機能していないようです。

なぜこのようなことがおこるのかご教示願えませんか？
よろしくお願いします。


<sample program>
--------------------------------------
#include <stdlib.h>
#include <stdio.h>

#include <time.h>


int main()
{
int i;
clock_t tick, base1, base2;
FILE *log_file;


log_file = fopen("LOGFILE.txt", "w");

base1 = clock();

printf("Start test program\n");

for (i = 1; i <= 1000; i++) {


base2 = clock();

_sleep(1);

tick = clock();
fprintf(log_file," sleeep time %d mS\n", tick - base2);
fprintf(log_file," tick %d mS base2 %d mS\n", tick, base2);


}

tick = clock();
fprintf(log_file," total time %d mS\n", tick - base1);
fprintf(log_file," tick %d mS base1 %d mS\n", tick, base1);

printf("End test program\n");


return 0;
}
-----------------------------------------

<out1>
---------------------
sleeep time 10 mS
tick 20 mS base2 10 mS
sleeep time 10 mS
tick 30 mS base2 20 mS
sleeep time 10 mS
tick 40 mS base2 30 mS
sleeep time 10 mS
tick 50 mS base2 40 mS
sleeep time 10 mS
tick 60 mS base2 50 mS
sleeep time 10 mS
tick 70 mS base2 60 mS
sleeep time 10 mS
tick 80 mS base2 70 mS
sleeep time 10 mS
tick 90 mS base2 80 mS
sleeep time 10 mS
tick 100 mS base2 90 mS
sleeep time 10 mS
tick 110 mS base2 100 mS
sleeep time 10 mS
tick 120 mS base2 110 mS
sleeep time 10 mS
tick 130 mS base2 120 mS
sleeep time 10 mS
tick 140 mS base2 130 mS
sleeep time 10 mS
tick 150 mS base2 140 mS
sleeep time 10 mS
tick 160 mS base2 150 mS
sleeep time 10 mS
tick 170 mS base2 160 mS
.
.
.
以下省略
---------------------
<out2>
---------------------
sleeep time 0 mS
tick 0 mS base2 0 mS
sleeep time 15 mS
tick 15 mS base2 0 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 0 mS
tick 15 mS base2 15 mS
sleeep time 16 mS
tick 31 mS base2 15 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 0 mS
tick 31 mS base2 31 mS
sleeep time 16 mS
tick 47 mS base2 31 mS
sleeep time 0 mS
tick 47 mS base2 47 mS
sleeep time 0 mS
tick 47 mS base2 47 mS
.
.
.
以下省略
---------------------

http://docs.embarcadero.com/products/ra ... p_xml.html
↑ここによりますと、
>停止時間の精度は，100 分の 1 秒またはオペレーティングシステムクロックの精度のどちらか低い方になります。
ということで、環境によって結果が異なるのが前提のようです。

回答ありがとうございます。m(__)m
私もこのURLは確認しました。
>停止時間の精度は，100 分の 1 秒またはオペレーティングシステムクロックの精度のどちらか低い方になります。
と書かれていますが、0カウントというのはないのではと思うのですが...。


また、同じPC（GateWay960ハード構成は同一）で同じO/S(Windows NT4.0 sp6)の２つのPCでも
片方は<OUT1>の様に_sleep()関数は毎回確実に作動するのにもう一方は<OUT2>の様に確実に作動しないという事象が発生しました。
この違いがなぜ発生するのかまったくわかりません。
よいアドバイスがありましたら是非ご教示ください。

とりあえず、単位がmsなら
tick - base2 ではなく
(tick - base2)*1000.0f/CLOCKS_PER_SEC
じゃないかなと思います。
%dなら1000.0fじゃなくて1000でも同じですが。。。
(CLOCKS_PER_SECが1000で、わざとそうしてるなら
ここは気にしないでください)

そもそも、↑のリンク先の_sleep()の説明を見ると引数は秒ですよね？
_sleep(1)で1秒止まるなら、ちゃんとした場合でも
10msでなく1000msが出るはずだと思うのですがそうはなってませんよね。

で、clockがプロセスが起動してから使用した時間を通知するとするなら、
sleepしてる間は他プロセスにCPUの使用権がいってるわけだから
数値は増えないんじゃないかと。

カウントが10だったり0だったりするのはそれこそ精度の違いで、
私の環境の場合、CLOCKS_PER_SECが1000でした。
つまり、clock()は1ms単位でしか刻まれないので
1ループにかかった時間がsleep()を除いて1ms以下では
まだカウントが変わらず差分が0になっているのだと思います。

(色々書きましたが、私も今ちょこっと調べてみただけなので
正しいかはわかりません……)

それほどまでの精度となると

i++;

のインクリメントだけでも1ms秒はかかるのではないでしょうか
実際に計ったわけではないので厳密にはわかりませんが

さらに fprintf() 関数が1ms秒で終わるということが前提でハードウェアの処理能力がないと
期待している精度は出ないでしょうね
メモリアクセス、メモリ上（でしょう）の数字の計算、関数の呼び出し、戻り値の処理
オペレーティングシステムの精度も考慮しないといけないはず

for (i = 1; i <= 1000; i++) { 


        base2 = clock(); 

        _sleep(1); 

        tick = clock(); 
        fprintf(log_file,"  sleeep time %d mS\n", tick - base2); 
        fprintf(log_file,"    tick %d mS  base2 %d mS\n", tick, base2); 


    }

ideyanさん、いろいろと調査頂き本当にありがとうございます。m(__)m

<out1>,<out2>どちらのPCもCLOCKS_PER_SECは1000です。
でsample programにより_sleep(1)を1000回繰り返すと
実際に処理にかかる時間は<out1>の場合10秒程度であり、<out2>の場合2秒程度となります。

また、それぞれ処理の最後に表示される'total time'は
次のように表示され、<out1>のtotal time 10014 mSと、<out2>のtotal time 1954 mS
は実際に処理にかかる時間と合致します。

そのため、やはり<out2>のPCの場合、_sleep()関数はまれにしか
実行されていないように思われます。
いかがでしょう？

皆さんお手数おかけします、よろしくお願いします。


<out1>
---------------------
sleeep time 10 mS
tick 10 mS base2 0 mS
sleeep time 10 mS
tick 20 mS base2 10 mS
sleeep time 10 mS
tick 30 mS base2 20 mS
sleeep time 10 mS
tick 40 mS base2 30 mS
sleeep time 10 mS
tick 50 mS base2 40 mS
sleeep time 10 mS
tick 60 mS base2 50 mS
sleeep time 10 mS
tick 70 mS base2 60 mS
sleeep time 10 mS
tick 80 mS base2 70 mS
sleeep time 10 mS
tick 90 mS base2 80 mS
sleeep time 10 mS
tick 100 mS base2 90 mS
sleeep time 10 mS
tick 110 mS base2 100 mS
sleeep time 10 mS
tick 120 mS base2 110 mS
sleeep time 10 mS
tick 130 mS base2 120 mS
sleeep time 10 mS
tick 140 mS base2 130 mS
sleeep time 10 mS
tick 150 mS base2 140 mS
sleeep time 10 mS
tick 160 mS base2 150 mS
sleeep time 10 mS
tick 170 mS base2 160 mS
sleeep time 10 mS
tick 180 mS base2 170 mS
.
途中省略
.
sleeep time 10 mS
tick 10014 mS base2 10004 mS
total time 10014 mS
tick 10014 mS base1 0 mS
---------------------

<out2>
---------------------
sleeep time 0 mS
tick 0 mS base2 0 mS
sleeep time 16 mS
tick 16 mS base2 0 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 0 mS
tick 16 mS base2 16 mS
sleeep time 16 mS
tick 32 mS base2 16 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 0 mS
tick 32 mS base2 32 mS
sleeep time 15 mS
tick 47 mS base2 32 mS
.
途中省略
.
sleeep time 0 mS
tick 1954 mS base2 1954 mS
total time 1954 mS
tick 1954 mS base1 0 mS
---------------------

dicさん、このsample programにて_sleep()関数を確認することになった経緯をご説明します。

ある製品を試験する試験装置に組み込まれたプログラムの処理の中で頻繁にデジタル通信を行っており
確実に通信を行うためにデータの受け渡しの前に_sleep(1)を挿入しておりました。
で、ある時期に新プログラムの検証用に新しいHDを用意し（2つのHDについて。O/Sはwindows nt 4.0 sp6で同様。器材ドライバも同様。VXIドライバのみバージョンアップ）それを使用して試験プログラムの検証を
実施したところ、試験時間が３時間４５から４時間半と大幅に伸びました。

遅延の原因を調査したところ、どうやらこれまでのHDを使用した場合は_sleep(1)が毎回確実に
動作していないためにその分処理が早かったことがわかりました。

そこで_sleep(1)を1000回実施するsample programを作成し、２つのHDでそれぞれ_sleep関数が確実に
動作するか確認することにしました。
すると、やはりこれまで使用していたHDでは_sleep(1)が毎回確実に動作せず、検証用に用意したHDでは
1000回全て確実に動作していました。
（注意、今回出力例として掲載した<OUT1>,<OUT2>のデータはこの2つのHDを使用した時のものではありません。）
そこで、これまで使用していたHDでも_sleep(1)が確実に動作するようにする方法はないか、その手がかりが
つかめればと今回、この質問を投稿させていただきました。

環境依存なので推測ですが、たぶん、

>_sleep()関数はまれにしか実行されていない

というより、out2では、「_sleep(1)で実際に1ms停止しいるが、clock()が精度が悪くて同じ値を返しているので 0ms と表示されている」のではないでしょうか。out1では「_sleep(1)で10msスリープしている」ように思います。

ループの中でIOせずに、
t=clock();
for(i=0;i<1000;i++) {
_sleep(1);
}
printf("%d\n",clock()-t);
とした時の結果は、環境１と２でどうなりますか？

マルチタスク
http://ja.wikipedia.org/wiki/%E3%83%9E% ... 9%E3%82%AF
>一方、OSがCPU時間を管理する必要があり、また、一定時間毎にタスク切り替え処理が発生するため、
>処理にはコストがかかる
を読んでみるといいかもしれません

Windows NT SP6 とあるのでマルチタスクを採用しているＯＳです
_sleep(1);　が成功していても他のプロセスにもCPUが割り当てられる可能性が高いため
仮に成功していても 1ms 秒以内にもとのプロセスにCPUが割り当てられる可能性がない
ということです

ＯＳが最適化をかけて実行していている場合もあります
コンパイラが最適化をかけている場合もあります

> それほどまでの精度となると
>
> i++;
>
> のインクリメントだけでも1ms秒はかかるのではないでしょうか
> 実際に計ったわけではないので厳密にはわかりませんが

発言の趣旨が分かりませんが、
もしもインクリメントに1msかかるとすると、
for (int i = 0; i < 10000; i++) { ; }
を抜けるのに10秒かかってしまいますよ。

今時のPCの場合、インクリメントにかかる時間は、
1ms(milli second : 10^-3秒)ではなく、
1ns(nano second : 10^-9秒)のオーダーです。

今、気が付いたんですが、
clock()関数は、プロセスのCPU使用時間を計測する関数だったと思うので、
_sleep()関数が、CPUを占有せずに、OSに返しているなら、
経過時間は計測出来ないかもしれませんよ。

>たいちうさん

>for (int i = 0; i < 10000; i++) { ; }
０（ゼロ）が一個おおいですよね＾＾；

>今時のPCの場合、インクリメントにかかる時間は、
>1ms(milli second : 10^-3秒)ではなく、
>1ns(nano second : 10^-9秒)のオーダーです。
実際に計ったわけではないので厳密にはわかりませんが
そうなのでしょうかね

> >for (int i = 0; i < 10000; i++) { ; }
> ０（ゼロ）が一個おおいですよね＾＾；

多くありません。1ms * 10000 = 10sec です。
十分長い時間を体感するため、10秒を計算結果にしています。


> 実際に計ったわけではないので厳密にはわかりませんが
> そうなのでしょうかね

私も計ったことはなく、今計ることに意味があるとも思いませんが、
あまりにも桁違いな予想が書かれていたのでしたので、
指摘させてもらいました。

>たいちうさん
すいません　質問者に対して回答しているので
たいちうさんの返答の内容がよくわからないです＾＾；

質問がそれるのでやめませんか？

> 質問がそれるのでやめませんか？

dicさんが理解できないならそれでも結構ですが、
あまりにもおかしい書き込みに対しては、
今後も指摘させていただきますね。

> 質問がそれるのでやめませんか？

そんなにそれてはいないと思いますよ。
一応、私もコメントしておくと...

> i++;
> のインクリメントだけでも1ms秒はかかるのではないでしょうか

Windows NTとかであれば、よほど性能の悪いインタープリタでもそれはないと思います。
あらゆる環境を考慮するなら、32kHzのクロックをプロセッサ内部で分周して使っているようなマイコンなら、1ms以上かかることもあり得ます。比較的ハイエンドな機種でも、消費電力を抑えるために低速モードが用意されていることはよくありますので。

> 実際に計ったわけではないので厳密にはわかりませんが

計測しなくても概算は可能です。

あと、

> もしもインクリメントに1msかかるとすると、
> for (int i = 0; i < 10000; i++) { ; }
> を抜けるのに10秒かかってしまいますよ。

intにvolatile修飾子がないので、ループ全体が削除される可能性が高いですね。

> やんちさん
http://www9.plala.or.jp/sgwr-t/lib/clock.html
↑のように、clock()関数は「プログラム実行開始からの経過時間」なので、問題ないと思いますが、もしかしてコンパイラによって違ったりするんでしょうかね？

> dicさん、たいちうさん
上のリンクの例では、
for (l=0; l<100000000; l++);
で 1.65秒 という結果に。私も、よほどの環境でなければそんなもんだろうな、と思います。

恐らくですがdicさんは
「1000回インクリメントを繰り返すだけで1msくらいかかるのではないか」
と言ったのに対してたいちうさんは
「インクリメント1回に1ms」
という認識をしてるのではないかと。
なので1000(元処理)と10000(サンプル)で0が1個多いという指摘をしてるのだと思います。

とりあえず「QueryPerformanceCounter」あたりを使うと良いのではないかとぽそっと呟いて去ります。

> http://www9.plala.or.jp/sgwr-t/lib/clock.html
> ↑のように、clock()関数は「プログラム実行開始からの経過時間」なので、問題ないと思いますが、もしかしてコンパイラによって違ったり> するんでしょうかね？

そのサイトの説明が間違っています。
clock関数はCPU使用時間を返します。
CPU使用時間が具体的に何を意味するのかは定義されていませんし、常に-1を返すことも許されています。

私もCPUの経過時間であるclock()よりは、QueryPerformanceCounterでシステム時間の経過で測った方が良いと思います。
指定時間自分のプロセスでCPUを使わないようにOSに依頼する_Sleepの時間をclock()で測る事自体が間違っています。

機器制御ということであれば、もしかすると計測用に何らかの信号を出力できる可能性もありますね。
だとすれば、QueryPerformanceCounterより、その信号を使ってオシロスコープかロジックアナライザで計測する方がずっと正確です。

試験時間が３時間４５分から４時間半に伸びたと言う話が問題なのですよね。
なので次のことを考え直してみてはどうでしょうか？

・_Sleep(1);に失敗していてちゃんと予定通りの動作をしていないと思われる３時間４５分のマシンの方は計測に失敗していなかったのでしょうか？
・もし失敗していないのなら_Sleep(1);は妥当に動作していたのではないでしょうか？
・単に時間が伸びたのは、NT側のプロセス/スレッド負荷の違いとは考えれないでしょうか？
・そもそも、試験時間は理想的にパソコンが動作したとして何時間で計測終了するのが正しいのでしょうか？
・理想と現実のギャップが大きい場合、なぜ理想値から遠いのかじっくり調べてみるのは出来ないのでしょうか？(もちろんCLOCK()以外の方法で)。

そもそもWindowsOSは時間通りきっちり動作するプログラムを動かすことは出来ませんので、RTOSの利用の検討やマイコンなどを使ったデータロガーを使えば悩みを解決出来るかもしれません。
※うまくいけば、試験時間の大幅短縮が出来る可能性も!

>for (int i = 0; i < 10000; i++) { ; }
これがどこからきたのかちょっと理解できないです


>hayakawaさん ねこさん　たかぎさん　softyaさん　ookamiさん　ideyanさん
私はマイコンのような機器を制御したことがないので
これ以上は何もいえないです


ただ、私が言いたかったのはWindowsなので、仮にｘmsで処理が完了しても
他のプログラムがエラーを起こしてそちらに処理時間が割り当てられる場合もありますってことでした


ひっこみますね

> >for (int i = 0; i < 10000; i++) { ; }
> これがどこからきたのかちょっと理解できないです

単なるインクリメントが1msもかかるわけがない、
ということを理解してもらうためのソースコードです。
回数に意味はなく以下のように別の数字でも構いません。
確実に体感できる10秒になる回数を選びました。

for (int i = 0; i < 100; i++) { ; } // i++ に 1ms かかるとすると、0.1秒かかる
for (int i = 0; i < 1000; i++) { ; } // i++ に 1ms かかるとすると、1秒かかる
for (int i = 0; i < 10000; i++) { ; } // i++ に 1ms かかるとすると、10秒かかる
for (int i = 0; i < 100000; i++) { ; } // i++ に 1ms かかるとすると、100秒かかる

念のため書くと、プログラムを実行するまでもなく10秒かからない事が分かるだろうから、
インクリメントに1msもかからないという事に気付いてもらおうという意図です。

たかぎさん
> そのサイトの説明が間違っています。
うわわわ、大変失礼しました。ご指摘ありがとうございます。

皆さんいろいろとご意見を頂き、ありがとうございます。

softyaさん
> 試験時間が３時間４５分から４時間半に伸びたと言う話が問題なのですよね。
ではなく、今まで３時間４５分で行われていたことが問題ではないかと考えています。

> なので次のことを考え直してみてはどうでしょうか？
> ・_Sleep(1);に失敗していてちゃんと予定通りの動作をしていないと思われる３時間４５分のマシンの方は計測に失敗していなかったのでしょうか？
> ・もし失敗していないのなら_Sleep(1);は妥当に動作していたのではないでしょうか？
> ・単に時間が伸びたのは、NT側のプロセス/スレッド負荷の違いとは考えれないでしょうか？
> ・そもそも、試験時間は理想的にパソコンが動作したとして何時間で計測終了するのが正しいのでしょうか？
> ・理想と現実のギャップが大きい場合、なぜ理想値から遠いのかじっくり調べてみるのは出来ないのでしょうか？(もちろんCLOCK()以外の方法で)。
_Sleep(1)の関数は1553バスを使用した通信でコマンドを送信する前に入れています。
このマシンは現在運用中ですが、時々原因不明の通信エラーでfailすることがあるので
今回見つかった_Sleep(1)関数が確実に機能していないのがその原因でないかと考えています。
同様の試験装置は本機を含め４台ありますが、試験時間が３時間４５分となるのはこの試験装置だけで
他３台の試験時間は4時間半です。
それぞれの試験装置は、使用するPCも計測器材もまちまちなのでハードの違いで試験時間に差が出るのでは
ないかと漠然と考えておりました。
しかし、今回わかったこと（試験時間が３時間４５分の試験装置では_Sleep()関数が確実に作動していない。）
が通信エラーでのfailの原因ではないかと考え、_Sleep()関数を確実に作動させるようにしたいと考えました。
そのために試験時間が4時間半に伸びても問題ないと考えています。
というか、それが正常な姿だと考えています。^^;