enqueue と dequeue
CPU がアイドル状態になると、ディスパッチャは、別の (アイドル状態でない) CPU のキューにある処理を探します。以下は、dequeue プローブを使って、アプリケーションがどの CPU によって、どのくらいの頻度で転送されるかを確認する例です。
#pragma D option quiet
sched:::dequeue
/args[2]->cpu_id != --1 && cpu != args[2]->cpu_id &&
(curlwpsinfo->pr_flag & PR_IDLE)/
{
@[stringof(args[1]->pr_fname), args[2]->cpu_id] =
lquantize(cpu, 0, 100);
}
END
{
printa("%s stolen from CPU %d by:\n%@d\n", @);
}
このスクリプトを 4 CPU システム上で実行した場合、出力の末尾部分は次のようになります。
# dtrace -s ./whosteal.d
^C
...
nscd stolen from CPU 1 by:
value -------------- Distribution ------------ count
1 | 0
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 28
3 | 0
snmpd stolen from CPU 1 by:
value -------------- Distribution ------------ count
< 0 | 0
0 |@ 1
1 | 0
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 31
3 |@@ 2
4 | 0
sched stolen from CPU 1 by:
value -------------- Distribution ------------ count
< 0 | 0
0 |@@ 3
1 | 0
2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 36
3 |@@@@ 5
4 | 0
|
どの CPU がどの処理を行なったかではなく、プロセスやスレッドが実行待ち状態になっている CPU について知りたい場合もあります。この場合も、enqueue プローブと dequeue プローブを組み合わせて使用します。
sched:::enqueue
{
self->ts = timestamp;
}
sched:::dequeue
/self->ts/
{
@[args[2]->cpu_id] = quantize(timestamp - self->ts);
self->ts = 0;
}
このスクリプトを数秒間実行すると、次のような出力が得られます。
# dtrace -s ./qtime.d
dtrace: script './qtime.d' matched 5 probes
^C
-1
value -------------- Distribution ------------ count
4096 | 0
8192 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2
16384 | 0
0
value -------------- Distribution ------------ count
1024 | 0
2048 |@@@@@@@@@@@@@@@ 262
4096 |@@@@@@@@@@@@@ 227
8192 |@@@@@ 87
16384 |@@@ 54
32768 | 7
65536 | 9
131072 | 1
262144 | 5
524288 | 4
1048576 | 2
2097152 | 0
4194304 | 0
8388608 | 0
16777216 | 1
33554432 | 2
67108864 | 2
134217728 | 0
268435456 | 0
536870912 | 0
1073741824 | 1
2147483648 | 1
4294967296 | 0
1
value -------------- Distribution ------------ count
1024 | 0
2048 |@@@@ 49
4096 |@@@@@@@@@@@@@@@@@@@@ 241
8192 |@@@@@@@ 91
16384 |@@@@ 55
32768 | 7
65536 | 3
131072 | 2
262144 | 1
524288 | 0
1048576 | 0
2097152 | 0
4194304 | 0
8388608 | 0
16777216 | 0
33554432 | 3
67108864 | 1
134217728 | 4
268435456 | 2
536870912 | 0
1073741824 | 3
2147483648 | 2
4294967296 | 0
|
末尾にゼロ以外の値が出力されている点に注目してください。これらのデータポイントから、どちらの CPU にも、スレッドの実行前に数秒間キューに入れられたインスタンスが、複数あることがわかります。
待ち時間ではなく、実行キューの長さの推移を調べたい場合もあります。このためには、enqueue プローブと dequeue プローブを使って、キューの長さを追跡する連想配列を設定します。
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 秒間実行すると、次のような出力が得られます。
# dtrace -s ./qlen.d
dtrace: script './qlen.d' matched 5 probes
^C
0
value -------------- Distribution ------------ count
< 0 | 0
0 |@@@@@@@@@@@@@@@@@@@@@@@@@ 110626
1 |@@@@@@@@@ 41142
2 |@@ 12655
3 |@ 5074
4 | 1722
5 | 701
6 | 302
7 | 63
8 | 23
9 | 12
10 | 24
11 | 58
12 | 14
13 | 3
14 | 0
|
アイドル状態のシステムに典型的な出力結果が得られます。 実行可能スレッドが入れられる時点の実行キューは、ほとんどの場合非常に短いものです (3 スレッド以下)。しかし、このシステムがたいていの場合アイドル状態にあることを考慮すると、表の下部に例外データポイントが出力されるのは、少し予想外かもしれません。たとえば、この実行キューに、実行可能スレッド 13 個分に相当する長さがなぜ必要なのでしょうか。この問題について調べるには、実行キューの長さが長いときに実行キューの内容を表示するような D スクリプトを作成します。この問題を複雑にしているのは、D の有効化です。D の有効化は、データ構造に対して繰り返し実行できないため、当然、実行キュー全体に対しても繰り返し実行できません。たとえ D の有効化にこれが可能であっても、カーネルの内部データ構造への依存関係は避けるべきです。
この種のスクリプトを実行するときは、enqueue プローブと dequeue プローブの両方を有効にし、投機アクションと連想配列の両方を使用します。スレッドがキューに入れられると、スクリプトによって、キューの長さが増分され、スレッドによりキー付けされた連想配列内のタイムスタンプが記録されます。この場合、スレッドは別のスレッドによってキューに入れられた可能性があるので、スレッド固有変数は使用できません。次に、キューの長さが上限を超えていないかどうかのチェックが行われます。上限を超えていた場合、新しい投機アクションが開始され、タイムスタンプと新しい上限値が記録されます。その後、スレッドがキューから外されると、キューに入れられた時点のタイムスタンプと最長のタイムスタンプとの比較が行われます。 スレッドが、最長のタイムスタンプより前にキューに入れられている場合、このスレッドは、最長のタイムスタンプが記録されとき、キュー内にあったことになります。この場合は、このスレッドの情報が投機的にトレースされます。最長のタイムスタンプの時点でキュー内にあったスレッドすべてがカーネルによってキューから外されると、スクリプトにより、投機データのコミットが行われます。以下に、このスクリプトを示します。
#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;
}
このスクリプトを、先ほどと同じ単一のプロセッサが搭載されたラップトップで実行すると、次のような出力が得られます。
# dtrace -s ./whoqueue.d Run queue of length 3: 0/0 (sched) 0/0 (sched) 101170/1 (dtrace) Run queue of length 4: 0/0 (sched) 100356/1 (Xsun) 100420/1 (xterm) 101170/1 (dtrace) Run queue of length 5: 0/0 (sched) 0/0 (sched) 100356/1 (Xsun) 100420/1 (xterm) 101170/1 (dtrace) Run queue of length 7: 0/0 (sched) 100221/18 (nscd) 100221/17 (nscd) 100221/16 (nscd) 100221/13 (nscd) 100221/14 (nscd) 100221/15 (nscd) Run queue of length 16: 100821/1 (xterm) 100768/1 (xterm) 100365/1 (fvwm2) 101118/1 (xterm) 100577/1 (xterm) 101170/1 (dtrace) 101020/1 (xterm) 101089/1 (xterm) 100795/1 (xterm) 100741/1 (xterm) 100710/1 (xterm) 101048/1 (xterm) 100697/1 (MozillaFirebird-) 100420/1 (xterm) 100394/1 (xterm) 100368/1 (xterm) ^C |
出力から、実行キューが長いのは、実行可能な xterm プロセスがたくさんあるせいだということがわかります。この測定と同時に、仮想デスクトップに変更が加えられています。したがって、上のような結果が得られた背景には、何らかの X イベント処理がかかわっていると推測できます。
- © 2010, Oracle Corporation and/or its affiliates