enqueue und dequeue
Wenn eine CPU in den Ruhezustand übergeht, sucht der Dispatcher nach Arbeit in den Warteschlangen anderer (belegter) CPUs. Im nächsten Beispiel soll anhand des Prüfpunkts dequeue beobachtet werden, wie oft und von welchen CPUs Anwendungen verschoben werden:
#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", @);
}
Der letzte Teil der Ausgabe, die Sie erhalten, wenn Sie dieses Skript auf einem System mit vier CPUs ausführen, lautet etwa:
# 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
|
Anstatt festzustellen, welche CPUs welche Arbeit übernommen haben, möchten Sie aber möglicherweise wissen, auf welchen CPUs Prozesse und Threads auf ihre Ausführung warten. Diese Frage können wir mit einer Kombination aus den Prüfpunkten enqueue und dequeue beantworten:
sched:::enqueue
{
self->ts = timestamp;
}
sched:::dequeue
/self->ts/
{
@[args[2]->cpu_id] = quantize(timestamp - self->ts);
self->ts = 0;
}
Wenn Sie das obige Skript einige Sekunden lang ausführen, erhalten Sie eine Ausgabe wie in folgendem Beispiel:
# 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
|
Beachten Sie die Werte ungleich Null am Ende der Beispielausgabe. Wie diese Datenpunkte zeigen, kam es auf beiden CPUs mehrmals vor, dass ein Thread mehrere Sekunden lang in der Ausführungswarteschlange stand.
Möglicherweise interessiert Sie aber nicht so sehr die jeweilige Wartezeit, sondern die Länge der Ausführungswarteschlange im Verlauf der Zeit. Mit den Prüfpunkten enqueue und dequeue können Sie einen assoziativen Vektor zum Ermitteln der Warteschlangenlänge einrichten:
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]—;
}
Wenn Sie das obige Skript ungefähr 30 Sekunden lang auf einem großteilig im Ruhezustand befindlichen Laptop-System ausführen, erhalten Sie eine Ausgabe wie in folgendem Beispiel:
# 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
|
Die Ausgabe entspricht grob den allgemeinen Erwartungen für ein System im Ruhezustand: Wenn ein ausführbarer Thread in die Warteschlange gestellt wird, ist die Warteschlange meistens sehr kurz (drei oder weniger Threads lang). Da sich aber das System großteilig im Ruhezustand befand, fallen die außergewöhnlichen Datenpunkte am Ende der Tabelle als eher unerwartet auf. Weshalb war zum Beispiel die Ausführungswarteschlange länger als 13 ausführbare Threads? Um dieser Frage auf den Grund zu gehen, könnten wir ein D-Skript schreiben, das den Inhalt der Ausführungswarteschlange anzeigt, wenn diese eine gewisse Länge erreicht. Das Problem ist allerdings recht komplex, da D-Aktivierungen nicht über Datenstrukturen wiederholt und folglich nicht einfach über der gesamten Ausführungswarteschlange wiederholt werden können. Selbst wenn dies möglich wäre, müssten Abhängigkeiten von den kernelinternen Datenstrukturen vermieden werden.
Für diese Art Skript würden wir die Prüfpunkte enqueue und dequeue aktivieren und sowohl Spekulationen als auch assoziative Vektoren verwenden. Immer wenn ein Thread in die Warteschlange gestellt wird, erhöht das Skript die Länge der Warteschlange und zeichnet die Zeitmarke in einem assoziativen Vektor mit Schlüssel des Threads auf. In diesem Fall kann keine thread-lokale Variable verwendet werden, da ein Thread auch durch einen anderen Thread in die Warteschlange gestellt werden kann. Das Skript überprüft dann, ob die Warteschlangenlänge das Maximum übersteigt. ist dies der Fall, beginnt das Skript eine neue Spekulation und zeichnet die Zeitmarke und das neue Maximum auf. Wenn dann ein Thread aus der Warteschlange gelöscht wird, vergleicht das Skript die Zeitmarke der Einreihung in die Warteschlange mit derjenigen der maximalen Länge: Wenn der Thread vor der Zeitmarke der maximalen Länge in die Warteschlange gestellt wurde, befand er sich bereits in der Warteschlange, als die maximale Länge aufgezeichnet wurde. In diesem Fall führt das Skript eine spekulative Ablaufverfolgung der Thread-Informationen durch. Wenn der Kernel den letzten zum Zeitpunkt der maximalen Länge eingereihten Thread aus der Warteschlange löscht, übergibt das Skript die Spekulationsdaten. Das Skript sieht wie folgt aus:
#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;
}
Die Ausführung des obigen Skripts auf demselben Einzelprozessor-Laptop erzeugt eine Ausgabe wie in folgendem Beispiel:
# 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 |
Die Ausgabe zeigt auf, dass die langen Ausführungswarteschlangen auf viele ausführbare xterm-Prozesse zurückzuführen sind. Dieses Experiment fiel mit einem Wechsel des virtuellen Desktops zusammen. Die Ergebnisse lassen sich deshalb wahrscheinlich durch eine Art der Verarbeitung von X-Ereignissen erklären.
- © 2010, Oracle Corporation and/or its affiliates