En enqueue y dequeue, el ejemplo final demuestra que la ráfaga en la longitud de la cola de ejecución está motivada por procesos xterm. Una hipótesis es que las observaciones estuvieron provocadas por un cambio en el escritorio virtual. Es posible utilizar el sondeo wakeup para explorar esta hipótesis determinando quién y cuándo está activando los procesos xterm, tal y como se muestra en el ejemplo siguiente:
#pragma D option quiet dtrace:::BEGIN { start = timestamp; } sched:::wakeup /stringof(args[1]->pr_fname) == "xterm"/ { @[execname] = lquantize((timestamp - start) / 1000000000, 0, 10); } profile:::tick-1sec /++x == 10/ { exit(0); }
Para investigar la hipótesis, ejecute la secuencia de comandos anterior, esperando unos cinco segundos, y cambie el escritorio virtual una única vez. Si la ráfaga de procesos no ejecutables xterm está motivada por un cambio de escritorio virtual, la salida debería mostrar una ráfaga de actividad de activación en la marca de cinco segundos.
# dtrace -s ./xterm.d Xsun value -------------- Distribution ------------ count 4 | 0 5 |@ 1 6 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 32 7 | 0 |
La salida muestra que el servidor X está activando procesos xterm, agrupados en torno al momento en el que cambiaron los escritorios virtuales. Si su intención era comprender la interacción entre el servidor X y los procesos xterm, podrá agregar en la pila de usuario marcas de seguimiento cuando el servidor X active el sondeo wakeup.
La comprensión del rendimiento de sistemas cliente/servidor tales como el sistema de ventanas X requiere comprender a los clientes en nombre de los cuales está realizando el trabajo el servidor. Este tipo de pregunta es difícil de responder con herramientas convencionales de análisis de rendimiento. Sin embargo, si cuenta con un modelo en el que un cliente envía un mensaje al servidor y pasa a inactividad esperando el procesamiento por parte del servidor, podría utilizar el sondeo wakeup para determinar el cliente para el que se está realizando la solicitud, tal y como se muestra en el siguiente ejemplo:
self int last; sched:::wakeup /self->last && args[0]->pr_stype == SOBJ_CV/ { @[stringof(args[1]->pr_fname)] = sum(vtimestamp - self->last); self->last = 0; } sched:::wakeup /execname == "Xsun" && self->last == 0/ { self->last = vtimestamp; }
La ejecución de la secuencia de comandos anterior devuelve una salida similar al siguiente ejemplo:
dtrace -s ./xwork.d dtrace: script './xwork.d' matched 14 probes ^C xterm 9522510 soffice.bin 9912594 fvwm2 100423123 MozillaFirebird 312227077 acroread 345901577 |
Esta salida revela que gran parte del trabajo Xsun se está realizando en nombre de los procesos acroread, MozillaFirebird y, en menor grado, fvwm2. Tenga en cuenta que la secuencia de comandos sólo examinó activaciones desde objetos de sincronización de variables de condición (SOBJ_CV). Tal y como se describe en la Tabla 25–4las variables de condición son el tipo de objeto de sincronización que suele utilizarse para sincronizar por razones diferentes al acceso a una región de datos compartida. En el caso del servidor X, un cliente esperará los datos en un sector de conducción esperando en inactividad en una variable de condición.
Asimismo, puede utilizar el sondeo sleep junto con el sondeo wakeup para saber qué aplicaciones están bloqueando en qué aplicaciones y durante cuánto tiempo, tal y como se muestra en el siguiente ejemplo:
#pragma D option quiet sched:::sleep /!(curlwpsinfo->pr_flag & PR_ISSYS) && curlwpsinfo->pr_stype == SOBJ_CV/ { bedtime[curlwpsinfo->pr_addr] = timestamp; } sched:::wakeup /bedtime[args[0]->pr_addr]/ { @[stringof(args[1]->pr_fname), execname] = quantize(timestamp - bedtime[args[0]->pr_addr]); bedtime[args[0]->pr_addr] = 0; } END { printa("%s sleeping on %s:\n%@d\n", @); }
La cola de la salida resultante de la ejecución de la secuencia de comandos de ejemplo durante varios segundos en un sistema de escritorio es similar al siguiente ejemplo:
# dtrace -s ./whofor.d ^C ... xterm sleeping on Xsun: value -------------- Distribution ------------ count 131072 | 0 262144 | 12 524288 | 2 1048576 | 0 2097152 | 5 4194304 |@@@ 45 8388608 | 1 16777216 | 9 33554432 |@@@@@ 83 67108864 |@@@@@@@@@@@ 164 134217728 |@@@@@@@@@@ 147 268435456 |@@@@ 56 536870912 |@ 17 1073741824 | 9 2147483648 | 1 4294967296 | 3 8589934592 | 1 17179869184 | 0 fvwm2 sleeping on Xsun: value -------------- Distribution ------------ count 32768 | 0 65536 |@@@@@@@@@@@@@@@@@@@@@@ 67 131072 |@@@@@ 16 262144 |@@ 6 524288 |@ 3 1048576 |@@@@@ 15 2097152 | 0 4194304 | 0 8388608 | 1 16777216 | 0 33554432 | 0 67108864 | 1 134217728 | 0 268435456 | 0 536870912 | 1 1073741824 | 1 2147483648 | 2 4294967296 | 2 8589934592 | 2 17179869184 | 0 34359738368 | 2 68719476736 | 0 syslogd sleeping on syslogd: value -------------- Distribution ------------ count 17179869184 | 0 34359738368 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 68719476736 | 0 MozillaFirebird sleeping on MozillaFirebird: value -------------- Distribution ------------ count 65536 | 0 131072 | 3 262144 |@@ 14 524288 | 0 1048576 |@@@ 18 2097152 | 0 4194304 | 0 8388608 | 1 16777216 | 0 33554432 | 1 67108864 | 3 134217728 |@ 7 268435456 |@@@@@@@@@@ 53 536870912 |@@@@@@@@@@@@@@ 78 1073741824 |@@@@ 25 2147483648 | 0 4294967296 | 0 8589934592 |@ 7 17179869184 | 0 |
Puede que desee comprender cómo y por qué razón MozillaFirebird se está bloqueando a sí mismo. Puede modificar la secuencia de comandos anterior del siguiente modo para responder a esta pregunta:
#pragma D option quiet sched:::sleep /execname == "MozillaFirebird" && curlwpsinfo->pr_stype == SOBJ_CV/ { bedtime[curlwpsinfo->pr_addr] = timestamp; } sched:::wakeup /execname == "MozillaFirebird" && bedtime[args[0]->pr_addr]/ { @[args[1]->pr_pid, args[0]->pr_lwpid, pid, curlwpsinfo->pr_lwpid] = quantize(timestamp - bedtime[args[0]->pr_addr]); bedtime[args[0]->pr_addr] = 0; } sched:::wakeup /bedtime[args[0]->pr_addr]/ { bedtime[args[0]->pr_addr] = 0; } END { printa("%d/%d sleeping on %d/%d:\n%@d\n", @); }
La ejecución de la secuencia de comandos modificada durante varios segundos devolverá una salida similar a la del siguiente ejemplo:
# dtrace -s ./firebird.d ^C 100459/1 sleeping on 100459/13: value -------------- Distribution ------------ count 262144 | 0 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 1048576 | 0 100459/13 sleeping on 100459/1: value -------------- Distribution ------------ count 16777216 | 0 33554432 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 67108864 | 0 100459/1 sleeping on 100459/2: value -------------- Distribution ------------ count 16384 | 0 32768 |@@@@ 5 65536 |@ 2 131072 |@@@@@ 6 262144 | 1 524288 |@ 2 1048576 | 0 2097152 |@@ 3 4194304 |@@@@ 5 8388608 |@@@@@@@@ 9 16777216 |@@@@@ 6 33554432 |@@ 3 67108864 | 0 100459/1 sleeping on 100459/5: value -------------- Distribution ------------ count 16384 | 0 32768 |@@@@@ 12 65536 |@@ 5 131072 |@@@@@@ 15 262144 | 1 524288 | 1 1048576 | 2 2097152 |@ 4 4194304 |@@@@@ 13 8388608 |@@@ 8 16777216 |@@@@@ 13 33554432 |@@ 6 67108864 |@@ 5 134217728 |@ 4 268435456 | 0 536870912 | 1 1073741824 | 0 100459/2 sleeping on 100459/1: value -------------- Distribution ------------ count 16384 | 0 32768 |@@@@@@@@@@@@@@ 11 65536 | 0 131072 |@@ 2 262144 | 0 524288 | 0 1048576 |@@@@ 3 2097152 |@ 1 4194304 |@@ 2 8388608 |@@ 2 16777216 |@ 1 33554432 |@@@@@@ 5 67108864 | 0 134217728 | 0 268435456 | 0 536870912 |@ 1 1073741824 |@ 1 2147483648 |@ 1 4294967296 | 0 100459/5 sleeping on 100459/1: value -------------- Distribution ------------ count 16384 | 0 32768 | 1 65536 | 2 131072 | 4 262144 | 7 524288 | 1 1048576 | 5 2097152 | 10 4194304 |@@@@@@ 77 8388608 |@@@@@@@@@@@@@@@@@@@@@@@ 270 16777216 |@@@ 43 33554432 |@ 20 67108864 |@ 14 134217728 | 5 268435456 | 2 536870912 | 1 1073741824 | 0 |
Puede utilizar también los sondeos sleep y wakeup para comprender el rendimiento de servidores puerta, como el daemon name service cache, tal y como se muestra en el siguiente ejemplo:
sched:::sleep /curlwpsinfo->pr_stype == SOBJ_SHUTTLE/ { bedtime[curlwpsinfo->pr_addr] = timestamp; } sched:::wakeup /execname == "nscd" && bedtime[args[0]->pr_addr]/ { @[stringof(curpsinfo->pr_fname), stringof(args[1]->pr_fname)] = quantize(timestamp - bedtime[args[0]->pr_addr]); bedtime[args[0]->pr_addr] = 0; } sched:::wakeup /bedtime[args[0]->pr_addr]/ { bedtime[args[0]->pr_addr] = 0; }
La cola de la salida al ejecutar la secuencia de comandos anterior en un gran servidor de correo es similar al siguiente ejemplo:
imapd value -------------- Distribution ------------ count 16384 | 0 32768 | 2 65536 |@@@@@@@@@@@@@@@@@ 57 131072 |@@@@@@@@@@@ 37 262144 | 3 524288 |@@@ 11 1048576 |@@@ 10 2097152 |@@ 9 4194304 | 1 8388608 | 0 mountd value -------------- Distribution ------------ count 65536 | 0 131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 49 262144 |@@@ 6 524288 | 1 1048576 | 0 2097152 | 0 4194304 |@@@@ 7 8388608 |@ 3 16777216 | 0 sendmail value -------------- Distribution ------------ count 16384 | 0 32768 |@ 18 65536 |@@@@@@@@@@@@@@@@@ 205 131072 |@@@@@@@@@@@@@ 154 262144 |@ 23 524288 | 5 1048576 |@@@@ 50 2097152 | 7 4194304 | 5 8388608 | 2 16777216 | 0 automountd value -------------- Distribution ------------ count 32768 | 0 65536 |@@@@@@@@@@ 22 131072 |@@@@@@@@@@@@@@@@@@@@@@@ 51 262144 |@@ 6 524288 | 1 1048576 | 0 2097152 | 2 4194304 | 2 8388608 | 1 16777216 | 1 33554432 | 1 67108864 | 0 134217728 | 0 268435456 | 1 536870912 | 0 |
Podría estar interesado en los inusuales puntos de datos para automountd o en el punto de datos persistente a más de un milisegundo para sendmail. Asimismo, puede añadir predicados a la secuencia de comandos anterior para conocer detalladamente las causas de cualquier tipo de resultado excepcional o anómalo.