Schedプロバイダ
schedプロバイダは、CPUスケジューリングに関連するプローブを使用可能にします。
CPUはすべてのスレッドが消費する必要がある1つのリソースであるため、schedプロバイダは、システムの動作を理解するのに役立ちます。
schedプローブ
次の表に、schedプロバイダのプローブを示します。 すべてのschedプローブについて、モジュールはvmlinuxで、関数は空の文字列です。
表9-12 schedプローブ
| プローブ | 説明 |
|---|---|
|
|
実行可能スレッドが実行キューからデキューされる直前に起動します。 実行キューに関連付けられたCPUは、 |
|
|
実行可能スレッドが実行キューにエンキューされる直前に起動します。 実行キューが特定のCPUに関連付けられていない場合、 |
|
|
現在のCPUがスレッドの実行を終了する直前に起動します。 |
|
|
CPUがスレッドの実行を開始したときに起動します。 現在のCPU、スレッドおよびプロセスは、それぞれ |
|
|
優先度の高いスレッドが実行可能になることが多いため、スケジューリングのディシジョンを行うように別のCPUからCPUに指示された場合に起動します。 |
|
|
クロック刻みベースのアカウンティングの一環として起動します。 クロック刻みベースのアカウンティングでは、固定間隔の割込みが発生したとき、どのスレッドとプロセスが実行されていたかを調べることによって、CPUのアカウンティングが実行されます。 |
|
|
現在のスレッドが同期オブジェクトでスリープしているスレッドを呼び出す直前に起動します。 ここで、 |
schedプローブの引数
これらのプローブの多くは、特定のスレッドを指します。 これらのプローブの場合、スレッドのlwpsinfo_tはargs[0]によって指され、スレッドを含むプロセスのpsinfo_tはargs[1]によって指されます。 いくつかのプローブは特定のCPUを指します。 cpuinfo_tは、args[2]によって示されます。 enqueueのみがargs[3]を持ち、その引数はブールです(説明を参照)。 argN値は実装に固有です。 かわりに、args[]を使用してプローブ引数にアクセスします。
次の表に、schedプロバイダのプローブ引数のサマリーを示します。
表9-13 schedプローブ引数
| プローブ | args[0] | args[1] | args[2] | args[3] |
|---|---|---|---|---|
|
|
|
|
|
- |
|
|
|
|
|
|
|
|
|
|
- |
- |
|
|
- |
- |
- |
- |
|
|
|
|
- |
- |
|
|
|
|
- |
- |
|
|
|
|
- |
- |
cpuinfo_t
cpuinfo_t構造体は、CPUを定義します。 enqueueプローブおよびdequeueプローブのargs[2]引数は、実行キューに関連付けられたCPUのcpuinfo_tを指します。これは、cpuinfo_tがcurcpu変数によって指される現在のCPUとは異なる場合があります。
cpuinfo_t構造体の定義は次のとおりです:
typedef struct cpuinfo {
processorid_t cpu_id;
psetid_t cpu_pset; /* not supported */
chipid_t cpu_chip;
lgrp_id_t cpu_lgrp; /* not supported */
} cpuinfo_t;schedの例
次の例は、schedプロバイダによって公開されるプローブの使用を示しています。
on-cpuおよびoff-cpu
回答が必要な一般的な質問の1つは、どのCPUsがスレッドを実行しているか、およびその期間ですか。 次の例では、on-cpuプローブとoff-cpuプローブを使用して、システム全体でこの質問に簡単に回答できます。 次のDソース・コードを入力し、where.dという名前のファイルに保存します:
sched:::on-cpu
{
self->ts = timestamp;
}
sched:::off-cpu
/self->ts/
{
@[cpu] = quantize(timestamp - self->ts);
self->ts = 0;
} スクリプトを実行します。 数秒後、Ctrl-Cを使用してスクリプトを取り消します。 出力は次のようになります:
0
value ------------- Distribution ------------- count
2048 | 0
4096 |@@ 37
8192 |@@@@@@@@@@@@@ 212
16384 |@ 30
32768 | 10
65536 |@ 17
131072 | 12
262144 | 9
524288 | 6
1048576 | 5
2097152 | 1
4194304 | 3
8388608 |@@@@ 75
16777216 |@@@@@@@@@@@@ 201
33554432 | 6
67108864 | 0
1
value ------------- Distribution ------------- count
2048 | 0
4096 |@ 6
8192 |@@@@ 23
16384 |@@@ 18
32768 |@@@@ 22
65536 |@@@@ 22
131072 |@ 7
262144 | 5
524288 | 2
1048576 | 3
2097152 |@ 9
4194304 | 4
8388608 |@@@ 18
16777216 |@@@ 19
33554432 |@@@ 16
67108864 |@@@@ 21
134217728 |@@ 14
268435456 | 0前の出力は、CPU 1のスレッドでは、ストレッチ時に131072ナノ秒未満(100マイクロ秒の順序)または8388608から134217728ナノ秒(約10から100ミリ秒)で実行される傾向があることを示しています。 2つのデータ・クラスタ間の顕著なギャップは、ヒストグラムに表示されます。 また、どのCPUが特定のプロセスを実行しているかを知りたい場合もあります。
on-cpuプローブおよびoff-cpuプローブを使用して、この問題に答えることもできます。 次のスクリプトは、指定したアプリケーションを10秒間実行するCPUsを表示します。 whererun.d.という名前のファイルに保存します:
#pragma D option quiet
dtrace:::BEGIN
{
start = timestamp;
}
sched:::on-cpu
/execname == $$1/
{
self->ts = timestamp;
}
sched:::off-cpu
/self->ts/
{
@[cpu] = sum(timestamp - self->ts);
self->ts = 0;
}
profile:::tick-10sec
{
exit(0);
}
dtrace:::END
{
printf("CPU distribution over %d seconds:\n\n",
(timestamp - start) / 1000000000);
printf("CPU microseconds\n--- ------------\n");
normalize(@, 1000);
printa("%3d %@d\n", @);
} 大きいメール・サーバーで前のスクリプトを実行し、IMAPデーモン(sudo dtrace -qs whererun.d imapdを使用)を指定すると、次のような出力になります:
CPU distribution of imapd over 10 seconds:
CPU microseconds
--- ------------
15 10102
12 16377
21 25317
19 25504
17 35653
13 41539
14 46669
20 57753
22 70088
16 115860
23 127775
18 160517 Oracle Linuxでは、スレッドを実行するCPUを選択するときにスレッドがスリープしている時間が考慮されます。これは、スリープしているスレッドが移行しない傾向があるためです。 この動作を監視するには、off-cpuプローブとon-cpuプローブを使用します。 次のソース・コードを入力し、howlong.dという名前のファイルに保存します:
sched:::off-cpu
/curlwpsinfo->pr_state == SSLEEP/
{
self->cpu = cpu;
self->ts = timestamp;
}
sched:::on-cpu
/self->ts/
{
@[self->cpu == cpu ?
"sleep time, no CPU migration" : "sleep time, CPU migration"] =
lquantize((timestamp - self->ts) / 1000000, 0, 500, 25);
self->ts = 0;
self->cpu = 0;
} スクリプトを実行します。 約30秒後に、Ctrl + Cを使用してスクリプトを取り消します。 出力は次のようになります:
sleep time, CPU migration
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@ 6838
25 |@@@@@ 4714
50 |@@@ 3108
75 |@ 1304
100 |@ 1557
125 |@ 1425
150 | 894
175 |@ 1526
200 |@@ 2010
225 |@@ 1933
250 |@@ 1982
275 |@@ 2051
300 |@@ 2021
325 |@ 1708
350 |@ 1113
375 | 502
400 | 220
425 | 106
450 | 54
475 | 40
>= 500 |@ 1716
sleep time, no CPU migration
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@ 58413
25 |@@@ 14793
50 |@@ 10050
75 | 3858
100 |@ 6242
125 |@ 6555
150 | 3980
175 |@ 5987
200 |@ 9024
225 |@ 9070
250 |@@ 10745
275 |@@ 11898
300 |@@ 11704
325 |@@ 10846
350 |@ 6962
375 | 3292
400 | 1713
425 | 585
450 | 201
475 | 96
>= 500 | 3946前の出力では、移行よりも多くの非移行が発生しています。 また、スリープ時間が長くなるほど、移行が発生しやすくなっています。 分布は100ミリ秒未満の範囲では異なりますが、スリープ時間が長くなるように見えます。 この結果は、特定のしきい値を超えると、スリープ時間がスケジューリングのディシジョンに反映されないことを示しています。
enqueueおよびdequeue
必要に応じて、実行を待機しているCPUsプロセスおよびスレッドを把握できます。 enqueueプローブとdequeueプローブを併用すると、この質問に回答できます。 次のソース・コードを入力し、qtime.dという名前のファイルに保存します:
sched:::enqueue
{
a[args[0]->pr_lwpid, args[1]->pr_pid, args[2]->cpu_id] =
timestamp;
}
sched:::dequeue
/a[args[0]->pr_lwpid, args[1]->pr_pid, args[2]->cpu_id]/
{
@[args[2]->cpu_id] = quantize(timestamp -
a[args[0]->pr_lwpid, args[1]->pr_pid, args[2]->cpu_id]);
a[args[0]->pr_lwpid, args[1]->pr_pid, args[2]->cpu_id] = 0;
}前述のスクリプトを数秒間実行すると、次のような出力になります:
1
value ------------- Distribution ------------- count
8192 | 0
16384 | 1
32768 |@ 47
65536 |@@@@@@@ 365
131072 |@@@@@@@@@@@@ 572
262144 |@@@@@@@@@@@@ 570
524288 |@@@@@@@ 354
1048576 |@ 57
2097152 | 7
4194304 | 1
8388608 | 1
16777216 | 0
0
value ------------- Distribution ------------- count
8192 | 0
16384 | 6
32768 |@ 49
65536 |@@@@@ 261
131072 |@@@@@@@@@@@@@ 753
262144 |@@@@@@@@@@@@ 704
524288 |@@@@@@@@ 455
1048576 |@ 74
2097152 | 9
4194304 | 2
8388608 | 0 待機時間を調べるのではなく、時間の経過とともに実行キューの長さを調べることができます。 enqueueプローブとdequeueプローブを使用すると、キューの長さを追跡する連想配列を設定できます。 次のソース・コードを入力し、qlen.dという名前のファイルに保存します:
sched:::enqueue
{
this->len = qlen[args[2]->cpu_id]++;
@[args[2]->cpu_id] = lquantize(this->len, 0, 100);
}
sched:::dequeue
/qlen[args[2]->cpu_id]/
{
qlen[args[2]->cpu_id]--;
}大部分がアイドル状態のデュアル・コア・プロセッサ・システムで前回のスクリプトを約30秒間実行すると、次のような出力になります:
1
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 8124
1 |@@@@@@ 1558
2 |@ 160
3 | 51
4 | 24
5 | 13
6 | 11
7 | 9
8 | 6
9 | 0
0
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 8569
1 |@@@@@@@@@ 2429
2 |@ 292
3 | 25
4 | 8
5 | 5
6 | 4
7 | 4
8 | 1
9 | 0出力は、アイドル状態のシステムで想定されるものです: 実行可能スレッドがエンキューされるほとんどの時間は、実行キューが短かった(長さが3個以下のスレッド)。 ただし、システムがほとんどアイドル状態であったため、各表の下部にある例外的なデータ・ポイントは予期しないものになる可能性があります。 たとえば、この実行キューが実行可能スレッド8個分だったのはなぜなのでしょうか。 この質問をさらに詳しく調べるには、実行キューが長い場合に実行キューの内容を表示するDスクリプトを記述します。 Dプローブはデータ構造に対して反復できないため、実行キュー全体に対して反復できないため、この問題は複雑です。 Dプローブがそれを実行できる場合でも、カーネルの内部データ構造体への依存関係を回避します。
このタイプのスクリプトでは、enqueueプローブとdequeueプローブを有効にしてから、投機と連想配列の両方を使用します。 たとえば、次のソース・コードを入力し、whoqueue.dという名前のファイルに保存します:
#pragma D option quiet
#pragma D option nspec=4
#pragma D option specsize=100k
int maxlen;
int spec[int];
sched:::enqueue
{
this->len = ++qlen[this->cpu = args[2]->cpu_id];
in[args[0]->pr_addr] = timestamp;
}
sched:::enqueue
/this->len > maxlen && spec[this->cpu]/
{
/*
* There is already a speculation for this CPU. We just set a new
* record, so weâll discard the old one.
*/
discard(spec[this->cpu]);
}
sched:::enqueue
/this->len > maxlen/
{
/*
* We have a winner. Set the new maximum length and set the timestamp
* of the longest length.
*/
maxlen = this->len;
longtime[this->cpu] = timestamp;
/*
* Now start a new speculation, and speculatively trace the length.
*/
this->spec = spec[this->cpu] = speculation();
speculate(this->spec);
printf("Run queue of length %d:\n", this->len);
}
sched:::dequeue
/(this->in = in[args[0]->pr_addr]) &&
this->in <= longtime[this->cpu = args[2]->cpu_id]/
{
speculate(spec[this->cpu]);
printf(" %d/%d (%s)\n",
args[1]->pr_pid, args[0]->pr_lwpid,
stringof(args[1]->pr_fname));
}
sched:::dequeue
/qlen[args[2]->cpu_id]/
{
in[args[0]->pr_addr] = 0;
this->len = --qlen[args[2]->cpu_id];
}
sched:::dequeue
/this->len == 0 && spec[this->cpu]/
{
/*
* We just processed the last thread that was enqueued at the time
* of longest length; commit the speculation, which by now contains
* each thread that was enqueued when the queue was longest.
*/
commit(spec[this->cpu]);
spec[this->cpu] = 0;
}このスクリプトでは、スレッドがエンキューされるたびに、キューの長さが増加し、スレッドがキーとなる連想配列にタイムスタンプが記録されます。 この場合、スレッドが別のスレッドによってエンキューされる可能性があるため、スレッド・ローカル変数は使用できません。 次に、スクリプトはキューの長さが最大値を超えているかどうかを確認し、この場合、スクリプトは新しい投機を開始して、タイムスタンプと新しい最大値を記録します。 次に、スレッドがデキューされると、enqueueのタイムスタンプと最大長のタイムスタンプが比較され、スレッドが最大長のタイムスタンプより前にエンキューされた場合、このスレッドは最大長のタイムスタンプが記録されとき、キューにあったことになります。 この場合、このスレッドの情報が投機的にトレースされます。 最大長のタイムスタンプでエンキューされた最後のスレッドがカーネルによってデキューされると、スクリプトによって投機データがコミットされます。
同じシステムで前のスクリプトを実行すると、次のような出力になります:
Run queue of length 1:
2850/2850 (java)
Run queue of length 2:
4034/4034 (kworker/0:1)
16/16 (sync_supers)
Run queue of length 3:
10/10 (ksoftirqd/1)
1710/1710 (hald-addon-inpu)
25350/25350 (dtrace)
Run queue of length 4:
2852/2852 (java)
2850/2850 (java)
1710/1710 (hald-addon-inpu)
2099/2099 (Xorg)
Run queue of length 5:
3149/3149 (notification-da)
2417/2417 (gnome-settings-)
2437/2437 (gnome-panel)
2461/2461 (wnck-applet)
2432/2432 (metacity)
Run queue of length 9:
3685/3685 (firefox)
3149/3149 (notification-da)
2417/2417 (gnome-settings-)
2437/2437 (gnome-panel)
2852/2852 (java)
2452/2452 (nautilus)
2461/2461 (wnck-applet)
2432/2432 (metacity)
2749/2749 (gnome-terminal)
^Cwakeup
次の例は、wakeupプローブを使用して、特定のプロセスをいつ、いつ、どこで起こっているかを確認する方法を示しています。 次のソース・コードを入力し、gterm.dという名前のファイルに保存します:
#pragma D option quiet
dtrace:::BEGIN
{
start = timestamp;
}
sched:::wakeup
/stringof(args[1]->pr_fname) == "gnome-terminal"/
{
@[execname] = lquantize((timestamp - start) / 1000000000, 0, 10);
}
profile:::tick-10sec
{
exit(0);
}このスクリプトを実行すると、次のような出力になります:
Xorg
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@@@@@@@@@@@ 69
1 |@@@@@@@@ 35
2 |@@@@@@@@@ 42
3 | 2
4 | 0
5 | 0
6 | 0
7 |@@@@ 16
8 | 0
9 |@@@ 15
>= 10 | 0 この出力は、システムと対話しながら、Xサーバーがgnome-terminalプロセスを起動していることを示しています。
tick
Oracle Linuxでは、「ティック・ベースのCPUアカウンティング」を使用できます。この場合、システム・クロック割込みは一定の間隔で起動され、CPU使用率はティック時に実行されているプロセスに帰属します。 次の例では、tickプローブを使用してこの属性を監視します。
sudo dtrace -n sched:::tick'{ @[stringof(args[1]->pr_fname)] = count() }'Ctrl + Cと入力すると、次のような出力が表示されます:
VBoxService 1
gpk-update-icon 1
hald-addon-inpu 1
jbd2/dm-0-8 1
automount 2
gnome-session 2
hald 2
gnome-power-man 3
ksoftirqd/0 3
kworker/0:2 3
notification-da 4
devkit-power-da 6
nautilus 9
dbus-daemon 11
gnome-panel 11
gnome-settings- 11
dtrace 19
khugepaged 22
metacity 27
kworker/0:0 41
swapper 56
firefox 58
wnck-applet 61
gnome-terminal 67
java 84
Xorg 227クロック刻みのアカウンティングには、アカウンティングを実行するシステム・クロックが原因で、時間に関係するスケジューリング・アクティビティがディスパッチされることがあるという短所があります。 スレッドがクロック・ティックごとに(10ミリ秒ごとに)一定量の作業を実行する場合、時間関連のディスパッチスケジューリングアクティビティの前または後にアカウンティングが実行されるかどうかに応じて、システムはスレッドのアカウント全体またはアカウントの下で行われます。 時間関連のディスパッチの前にアカウンティングが実行されると、システムは一定の間隔で実行されているスレッドを考慮します。 このようなスレッドが、クロック間隔より短く実行された場合、クロック間隔の裏に隠すことができます。
次の例では、このようなスレッドがシステムにあるかどうかを調べます。 次のソース・コードを入力し、tick.dという名前のファイルに保存します:
sched:::tick,
sched:::enqueue
{
@[probename] = lquantize((timestamp / 1000000) % 10, 0, 10);
} この例のスクリプトを実行した出力結果を見ると、10ミリ秒の間隔でミリ秒のオフセットが2つ存在することがわかります。1つはtickプローブのオフセット、もう1つはenqueueのオフセットです。
tick
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@@ 29
1 |@@@@@@@@@@@@@@@@@@@ 106
2 |@@@@@ 27
3 |@ 7
4 |@@ 10
5 |@@ 12
6 |@ 4
7 |@ 8
8 |@@ 9
9 |@@@ 17
>= 10 | 0
enqueue
value ------------- Distribution ------------- count
< 0 | 0
0 |@@@@ 82
1 |@@@@ 86
2 |@@@@ 76
3 |@@@ 65
4 |@@@@@ 101
5 |@@@@ 79
6 |@@@@ 75
7 |@@@@ 76
8 |@@@@ 89
9 |@@@@ 75
>= 10 | 0 tickという出力ヒストグラムは、クロックのティックが1ミリ秒のオフセットで起動していることを示しています。 この例では、enqueueの出力は10ミリ秒間隔で均等に分散され、1ミリ秒でスパイクが表示されないため、スレッドは時間ベースでスケジュールされていないようです。