[an error occurred while processing this directive]
[an error occurred while processing this directive](watch.c) #include <stdio.h> #include <sys/time.h> int main(void){ int i, j, temp; long dt; struct timeval tv0, tv1; gettimeofday(&tv0, 0); /* 時間0測定 */ for(i = 0; i < 1000 * 100; i++){ /* 重いループ */ for(j = 0; j < 1000; j++) temp = i * j; } gettimeofday(&tv1, 0); /* 時間1測定 */ dt = (tv1.tv_sec - tv0.tv_sec) * 1000 * 1000 + (tv1.tv_usec - tv0.tv_usec); /* 時間の差を計算 */ printf("elapsed time : %ld usec\n", dt); /* 経過時間表示 */ return 0; }このプログラムを実行すると、542181 usecと出ました。つまり、このループの実行には542ミリ秒かかったようです。
(baka.c) int main(void){ for(;;); /* 無限に繰り返し */ }この無限に資源を浪費する;pプログラムと先程の計時をするプログラムを同時に走らせてみます。 なお、ターミナルからコマンドの最後に&を付けて実行すると、そのプログラムは「バックグラウンド」で実行されます。
> ps 今動いているプロセスを表示 PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1892 pty/s1 00:00:00 ps > ./watch 計時プログラムを実行 elapsed time : 542181 nsec > ./baka & 無限ループプログラムを実行 [1] 1894 > ps PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1894 pty/s1 00:00:03 baka 無限ループが動いている 1895 pty/s1 00:00:00 ps > ./watch 計時プログラムを実行 elapsed time : 1051538 nsec 先程の約二倍の時間がかかる > ./baka & さらに無限ループプログラムを実行 [2] 1897 > ps PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1894 pty/s1 00:00:09 baka 一つ目の無限ループ 1897 pty/s1 00:00:00 baka 二つ目の無限ループ 1898 pty/s1 00:00:00 ps > ./watch 計時プログラムを実行 elapsed time : 1547684 nsec 先程の約三倍の時間がかかる > killall baka 後始末 [2] Terminated ./baka [1] Terminated ./bakaこのように、同じように計算を行い続けるプログラムでは、資源が均等に配分され、 同時にプログラムを二つ走らせると時間は二倍、三つ走らせると三倍の時間がかかることがわかります。
(itrpt.c)※抜粋です ... #includeこのプログラムを実行すると、以下のような結果が得られます。なお、これは先のbaka.cと同時に実行した場合のものです。#define RDTSC(X) __asm__ __volatile__ ("rdtsc" : "=A" (X)); ... for(i = 0; i < imax; i++){ /* ループ */ RDTSC(c1); /* クロック取得 */ dc = c1 - c0; /* 前のクロックとの差(経過クロック)を取得 */ c0 = c1; CNT[(int)(log(dc)/log(2.0))]++; /* 経過クロックを記録 */ } ...
** Clock info ** 1296.685347 MHz クロック数を経過時間で割ることで、CPUの動作周波数が分かる 上のループを一回周るのにかかった時間の分布。 [c]クロック(それは[t]秒に当たる)かかった頻度は[n]回で、一秒間に換算すると[f]回おこった、 と見て下さい。 [c] [t] [n] [f] 128 clk 98.72 n sec 0 0.0 Hz 256 clk 197.44 n sec 2999809 2070175.9 Hz 割り込まれなかった時の時間 512 clk 394.88 n sec 33 22.8 Hz 1 k clk 789.75 n sec 1 0.7 Hz 2 k clk 1.58 u sec 0 0.0 Hz 4 k clk 3.16 u sec 0 0.0 Hz 8 k clk 6.32 u sec 88 60.7 Hz システムタイマ割り込みが発生し、すぐ復帰した時 16 k clk 12.64 u sec 6 4.1 Hz 32 k clk 25.27 u sec 1 0.7 Hz 65 k clk 50.54 u sec 40 27.6 Hz 131 k clk 101.09 u sec 1 0.7 Hz 262 k clk 202.18 u sec 0 0.0 Hz 524 k clk 404.35 u sec 0 0.0 Hz 1 M clk 808.70 u sec 0 0.0 Hz 2 M clk 1.62 m sec 0 0.0 Hz 4 M clk 3.23 m sec 0 0.0 Hz 8 M clk 6.47 m sec 2 1.4 Hz 16 M clk 12.94 m sec 1 0.7 Hz 33 M clk 25.88 m sec 8 5.5 Hz 67 M clk 51.76 m sec 8 5.5 Hz 割り込みからなかなか復帰しなかった時 134 M clk 103.51 m sec 2 1.4 Hz 268 M clk 207.03 m sec 0 0.0 Hz me : 0.592289 sec 1000クロック以下のものを合計した時間 others: 0.856771 sec それ以上かかった時を合計した時間 ratio : 40.9 % CPU占有率(割り込まれなかった時間 / 全時間)一回のループが十分に軽いので、割り込みが起こった時と起こらなかった時ははっきりと区別できます。(時間の軸はlogで取っていることに注意して下さい) なお、システムタイマ割り込みは僕の環境では100Hzですが、他のプロセスにCPUを取られている間は感知することができないので、上ではそれより小さい値(60Hz)になっています。 もっと実行時間を短くして実験すると、100Hzに近い値が得られました。
(thief.c) #includeこれについても、先程と同様に他のプログラムと同時に実行した時の挙動を調べてみます。#include long check_time(struct timeval *tp){ /** tpと現在時刻の差を返す(usec) */ struct timeval t1; gettimeofday(&t1, 0); /* 現在時刻を取得 */ return (t1.tv_sec - tp->tv_sec) * 1000 * 1000 + (t1.tv_usec - tp->tv_usec); /* 引数との時刻の差をnsec単位で返す */ } int main(void){ int i, j, temp; long dt; struct timeval tv, tv0, tv1; double thres; struct timespec ts0, ts1; ts0.tv_sec = 0, ts0.tv_nsec = 0; thres = 9 * 1000; /* しきい値を9msec(9000usec)に設定 */ gettimeofday(&tv0, 0); /* 時間0測定 */ for(i = 0; i < 100 * 1000; i++){ /* ループ */ for(j = 0; j < 1000; j++) temp = i * j; if(check_time(&tv) > thres){ /* 時間tvからthres nsec以上経過したら */ nanosleep(&ts0, &ts1); /* 一時スリープ */ gettimeofday(&tv, 0); /* tvに起きた時刻をセット */ } } gettimeofday(&tv1, 0); /* 時間1測定 */ dt = (tv1.tv_sec - tv0.tv_sec) * 1000 * 1000 + (tv1.tv_usec - tv0.tv_usec); /* 時間の差を計算 */ printf("elapsed time : %ld usec\n", dt); /* 経過時間表示 */ return 0; }
> ps 今動いているプロセスを表示 PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1909 pty/s1 00:00:00 ps > ./thief 計時(?)プログラムを実行 elapsed time : 634654 nsec 時間は先程より少し遅い > ./baka & 無限ループプログラムを実行 [1] 1911 > ps PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1911 pty/s1 00:00:01 baka 無限ループが動いている 1912 pty/s1 00:00:00 ps > ./thief 計時(?)プログラムを実行 elapsed time : 656277 nsec 時間はあまり変わらない > ./baka & 無限ループプログラムを実行 [2] 1914 > ps PID TTY TIME CMD 1851 pty/s1 00:00:00 tcsh 1911 pty/s1 00:00:08 baka 一つ目の無限ループ 1914 pty/s1 00:00:00 baka 二つ目の無限ループ 1915 pty/s1 00:00:00 ps > ./thief 計時(?)プログラムを実行 elapsed time : 638081 nsec 時間はあまり変わらない > killall baka 後始末 [2] Terminated ./baka [1] Terminated ./bakaこのように、thief.cでは他のプロセスの数にかかわりなく、いつもほぼ一定の実行時間となっています。 つまり、他のプロセスと関係無くCPUを占有できているわけです。
top - 18:47:46 up 27 min, 3 users, load average: 0.68, 0.32, 0.24 Tasks: 38 total, 5 running, 33 sleeping, 0 stopped, 0 zombie Cpu(s): 99.8% user, 0.2% system, 0.0% nice, 0.0% idle Mem: 515320k total, 94196k used, 421124k free, 4112k buffers Swap: 0k total, 0k used, 0k free, 40824k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1940 kei 20 0 224 224 188 R 47.0 0.0 0:12.40 baka 1941 kei 20 0 224 224 188 R 47.0 0.0 0:11.52 baka 1840 root 19 0 26732 23m 2036 R 5.2 4.6 0:07.03 X 1942 kei 9 0 232 232 196 R 0.6 0.0 0:00.11 thief_longなお、実際にはI/O割り込みなどの影響もあるので、他のプロセスが全く使えないわけではありません。通常のエディタやターミナルといった専らI/Oを用いるプログラムでは、このthiefの影響を余り受けていないように感じました。
... #includeこうして、先程と同様にbaka.cと共に実行し、割り込みの様子を調べたのが以下です。#define RDTSC(X) __asm__ __volatile__ ("rdtsc" : "=A" (X)); ... for(i = 0; i < imax; i++){ /* ループ */ RDTSC(c1); /* クロック取得 */ dc = c1 - c0; /* 前のクロックとの差(経過クロック)を取得 */ c0 = c1; CNT[(int)(log(dc)/log(2.0))]++; /* 経過クロックを記録 */ if(c1 - ca > thres){ /* 時間caからthresクロック以上経過したら */ nanosleep(&ts0, &ts1); /* 一時スリープ */ RDTSC(ca); /* caに起きた時刻をセット */ } } ...
128 clk 98.71 n sec 0 0.0 Hz 256 clk 197.42 n sec 2999678 4225901.4 Hz 割り込まれなかった時 512 clk 394.84 n sec 26 36.6 Hz 1 k clk 789.67 n sec 128 180.3 Hz nanosleepした時 2 k clk 1.58 u sec 0 0.0 Hz 4 k clk 3.16 u sec 0 0.0 Hz 8 k clk 6.32 u sec 0 0.0 Hz 16 k clk 12.63 u sec 2 2.8 Hz 割り込みが発生したが、すぐに復帰した時 32 k clk 25.27 u sec 0 0.0 Hz 65 k clk 50.54 u sec 37 52.1 Hz 131 k clk 101.08 u sec 0 0.0 Hz 262 k clk 202.16 u sec 0 0.0 Hz 524 k clk 404.31 u sec 0 0.0 Hz 1 M clk 808.63 u sec 127 178.9 Hz 2 M clk 1.62 m sec 0 0.0 Hz 4 M clk 3.23 m sec 0 0.0 Hz 8 M clk 6.47 m sec 2 2.8 Hz 16 M clk 12.94 m sec 0 0.0 Hz sleep : 128 times nanosleepした回数 me : 0.592303 sec others: 0.117529 sec ratio : 83.4 %上はsleepするしきい値を9msecにした場合ですが、チューニングすると、もっと資源を独占することができます。しかし、毎回安定して90%以上を占有するのはきついようです。これはおそらく他のスリープしているプロセスや、I/O割り込みの影響だと思われます。ちゃんと統計を取ったわけではありませんが、Xを立ち上げず、ネットワークにも接続しない状態の方が、毎回安定した結果が出た気がします。
(linux/kernel/timer.c) void update_process_times(int user_tick) { ... pというのは現在実行中のプロセス構造体(へのポインタ)で、counterに実行優先度が格納されています if (--p->counter <= 0) {1ずつ引いているだけです p->counter = 0; } ... }この関数はシステムタイマ割り込みが発生するたびに呼び出されているものと思われます。
(linux/kernel/sched.c) /* * 'schedule()' is the scheduler function. It's a very simple and nice * scheduler: it's not perfect, but certainly works for most things. * 完璧ではないけど、シンプルでniceらしい */ asmlinkage void schedule(void) { ... 実行中のプロセスにつき、実行を続けるかを判断 prev = current; this_cpu = prev->processor; ... /* move an exhausted RR process to be last.. */ if (unlikely(prev->policy == SCHED_RR)) if (!prev->counter) { 実行中のプロセスのcounterが0なら、値をリセットして実行キューの最後へ NICE_TO_TICKSってのは、単にniceの値にある値を掛けているだけ。 prev->counter = NICE_TO_TICKS(prev->nice); move_last_runqueue(prev); } ... /* * Default process to select.. */ 現在実行待ちのプロセスで、実行優先度から計算されるgoodnessが最大のものを探す list_for_eachは、マクロとgotoで実現しているみたい next = idle_task(this_cpu); c = -1000; list_for_each(tmp, &runqueue_head) { p = list_entry(tmp, struct task_struct, run_list); if (can_schedule(p, this_cpu)) { int weight = goodness(p, this_cpu, prev->active_mm); if (weight > c) c = weight, next = p; } } /* Do we need to re-calculate counters? */ 実行待ちのプロセスのgoodnessがどれも小さければ、実行優先度を再計算 if (unlikely(!c)) { struct task_struct *p; ... 各実行プロセスについて、現在の実行優先度を2で割って、nice値の定数倍を掛けている for_each_taskは、マクロとgotoで実現しているみたい。2で割るのはビットシフト使ってます for_each_task(p) p->counter = (p->counter >> 1) + NICE_TO_TICKS(p->nice); ... } /* * from this point on nothing can prevent us from * switching to the next task, save this fact in * sched_data. */ 実行プロセスを切り変え sched_data->curr = next; task_set_cpu(next, this_cpu); ... }マクロが多かったりで読みにくいですが、なんとなくどこで何をしているのかは分かる気がします。 後でFreeBSDのソースも少しだけ見てみたのですが、Linuxの方がすっきりしていると感じました。
linux/arch/i386/kernel/entry.S
...
ENTRY(system_call)
pushl %eax # save orig_eax
SAVE_ALL
...
.long SYMBOL_NAME(sys_nanosleep)
...
名前からして、このsys_nanosleep()という関数がnanosleep()の実体のようです。これは、/usr/src/linux/kernel/timer.cという「それっぽい」所にあります。
(linux/kernel/timer.c) asmlinkage long sys_nanosleep(struct timespec *rqtp, struct timespec *rmtp) { ... ここにはリアルタイム処理やエラー処理が書かれているが、今回は関係ない... expire = timespec_to_jiffies(&t) + (t.tv_sec || t.tv_nsec); current->state = TASK_INTERRUPTIBLE; expire = schedule_timeout(expire); ...この"expire"というのは、スリープする時間のようです。このexpireをschedule_timeout()に送っている、というのは、expireの時間だけ他のプログラムを実行させているのでしょう。 というわけで、次はschedule_timeout()を調べてみます。
(linux/kernel/sched.c) * 1998-11-19 Implemented schedule_timeout() and related stuff * by Andrea Arcangeli schedule_timeout()は割と新しい関数らしい。機能的に考えてnanosleep専用かも ... /** * schedule_timeout - sleep until timeout * @timeout: timeout value in jiffies jiffyは'一瞬'て意味 ... */ signed long schedule_timeout(signed long timeout) { struct timer_list timer; unsigned long expire; ... expire = timeout + jiffies; init_timer(&timer); 新しいタイマ割り込みを定義する timer.expires = expire; timer.data = (unsigned long) current; timer.function = process_timeout; add_timer(&timer); 新しいタイマ割り込みを定義する schedule(); スケジューリング del_timer_sync(&timer);後始末 ... }この過程でnanosleepを呼び出したプロセスのcounterは全く減らされないようです。 そこで、今回はお手軽改造ということで、ここでnanosleep()を呼び出したプロセスの実行優先度を下げてみました。
...
add_timer(&timer);
current->counter--; 現在のプロセスの実行優先度を減らす
schedule();
del_timer_sync(&timer);
...
currentというのは現在のプロセスの情報を保持している構造体へのポインタで、グローバル変数のようです。> ps PID TTY TIME CMD 1717 pty/s1 00:00:00 tcsh 1818 pty/s1 00:00:00 ps > ./thief 計時(?)プログラムを実行 elapsed time : 638342 nsec > ./baka & 無限ループプログラムを実行 [1] 1820 > ps PID TTY TIME CMD 1717 pty/s1 00:00:00 tcsh 1820 pty/s1 00:00:02 baka 1822 pty/s1 00:00:00 ps > ./thief 計時(?)プログラムを実行 elapsed time : 1158259 nsec 処理時間は1.8倍になっている。 > ./baka & さらに無限ループプログラムを実行 [2] 1824 > ps PID TTY TIME CMD 1717 pty/s1 00:00:00 tcsh 1820 pty/s1 00:00:09 baka 1824 pty/s1 00:00:00 baka 1825 pty/s1 00:00:00 ps > ./thief 計時プログラムを実行 elapsed time : 1576880 nsec 処理時間は2.5倍になっている。先程よりは資源が公平に配分されているようです。 次に、topの出力を見てみます。
top - 16:46:52 up 2:11, 3 users, load average: 2.85, 1.16, 0.48 Tasks: 45 total, 6 running, 39 sleeping, 0 stopped, 0 zombie Cpu(s): 98.7% user, 1.3% system, 0.0% nice, 0.0% idle Mem: 515728k total, 159300k used, 356428k free, 6608k buffers Swap: 0k total, 0k used, 0k free, 86268k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 2276 kei 20 0 224 224 188 R 33.3 0.0 0:08.28 baka 2277 kei 20 0 224 224 188 R 33.0 0.0 0:07.56 baka 2278 kei 17 0 228 228 192 R 33.0 0.0 0:03.57 thief_long 1706 root 16 0 28160 24m 2236 S 0.7 4.9 1:41.01 Xこちらも期待通りの結果が出ているようです。
** Clock info ** 1692.058619 MHz 128 clk 75.65 n sec 1 1.6 Hz 256 clk 151.29 n sec 0 0.0 Hz 512 clk 302.59 n sec 0 0.0 Hz 1 k clk 605.18 n sec 999836 1648207.1 Hz 2 k clk 1.21 u sec 0 0.0 Hz 4 k clk 2.42 u sec 0 0.0 Hz 8 k clk 4.84 u sec 54 89.0 Hz 16 k clk 9.68 u sec 98 161.6 Hz 32 k clk 19.37 u sec 7 11.5 Hz 65 k clk 38.73 u sec 3 4.9 Hz 131 k clk 77.46 u sec 1 1.6 Hz 262 k clk 154.93 u sec 0 0.0 Hz me : 0.605081 sec others: 0.001540 sec ratio : 99.7この結果から、8msecおきにnanosleepさせるように先程のプログラムを調整して実行してみたのですが、戦果は芳しくありませんでした。CPUは50%しか取れないし、topコマンドでもCPU占有率が表示されてしまいます。
** Clock info ** Clock : 4357520 Time : 2576 1691.583851 MHz thres : 16492942 elapsed clock : -- slept time and elapsed time -- かかった時間 sleep一回 実行+sleep 171.87 u sec 60 0 100usec。スリープさせた時間 206.25 u sec 49 0 427.68 u sec 305 0 200usec。スリープさせた時間 513.22 u sec 7 0 615.86 u sec 1 0 739.03 u sec 1 0 1.84 m sec 1 0 9.49 m sec 2 391 1000usec。1サイクルの時間 11.39 m sec 0 1 16.40 m sec 0 2 19.68 m sec 2 2 28.33 m sec 3 5 34.00 m sec 4 4 40.80 m sec 0 1 48.96 m sec 2 9 58.75 m sec 4 12 他のプログラムに資源が奪われた時の時間 70.50 m sec 2 2 84.60 m sec 5 11 101.52 m sec 0 7 303.14 m sec 0 1 sleep : 448 times sleepさせた回数 me : 3.487460 sec others: 3.404902 sec ratio : 50.6 ちゃんとスケジューリングされています >というわけで、うまくいっていません。 また、Linuxよりも実行開始直後のプログラムにより多くの資源が与えられる気がしました。
kern_time.h static int nanosleep1(p, rqt, rmt) struct proc *p; struct timespec *rqt, *rmt;/*関数宣言の書き方が古い…*/ { ... TIMESPEC_TO_TIMEVAL(&tv, rqt); for (;;) { error = tsleep(&nanowait, PWAIT | PCATCH, "nanslp", /* このtsleepを適宜呼ぶことでスリープする */ ...