O provedor sched disponibiliza os testes relacionados ao agendamento de CPU. Como as CPUs são o único recurso que todos os segmentos devem consumir, o provedor sched é muito útil para a compreensão do comportamento sistêmico. Por exemplo, ao usar o provedor sched, você pode compreender quando e por que os segmentos entram em espera, são executados, mudam de prioridade ou ativam outros segmentos.
Os testes sched são descritos na Tabela 26–1.
Tabela 26–1 Testes sched
Teste |
Descrição |
---|---|
change-pri |
Teste que é acionado sempre que a prioridade de um segmento está para ser alterada. A lwpsinfo_t do segmento é apontada por args[0] . A prioridade atual do segmento está no campo pr_pri desta estrutura. A psinfo_t do processo que contém o segmento é apontada por args[1]. A nova prioridade do segmento está contida em args[2]. |
dequeue |
Teste que é acionado imediatamente antes de um segmento executável ser desenfileirado de uma fila de execução. A lwpsinfo_t do segmento que está sendo desenfileirado é apontada por args[0]. A psinfo_t do processo que contém o segmento é apontada por args[1]. A cpuinfo_t da CPU da qual o segmento está sendo desenfileirado é apontada por args[2]. Se o segmento estiver sendo desenfileirado de uma fila de execução que não esteja associada a uma CPU em particular, o membro cpu_id dessa estrutura será -1. |
enqueue |
Teste que é acionado imediatamente antes de um segmento executável ser enfileirado em uma fila de execução. A lwpsinfo_t do segmento que está sendo enfileirado é apontada por args[0]. A psinfo_t do processo que contém o segmento é apontada por args[1]. A cpuinfo_t da CPU na qual o segmento está sendo enfileirado é apontada por args[2]. Se o segmento estiver sendo enfileirado em uma fila de execução que não esteja associada a uma CPU em particular, o membro cpu_id dessa estrutura será -1. O valor em args[3] é um booleano que indica se o segmento será enfileirado na frente da fila de execução. O valor será diferente de zero se o segmento for enfileirado na frente da fila de execução, e zero se o segmento for enfileirado na parte de trás da fila de execução. |
off-cpu |
Teste que é acionado quando a CPU atual estiver prestes a encerrar a execução de um segmento. A variável curcpu indica a CPU atual. A variável curlwpsinfo indica o segmento que está encerrando a execução. A variável curpsinfo descreve o processo que contém o segmento atual. A estrutura lwpsinfo_t do segmento que a CPU atual executará em seguida é apontada por args[0] . A psinfo_t do processo que contém o próximo segmento é apontada por args[1]. |
on-cpu |
Teste que é acionado quando uma CPU inicia a execução de um segmento. A variável curcpu indica a CPU atual. A variável curlwpsinfo indica o segmento que está iniciando a execução. A variável curpsinfo descreve o processo que contém o segmento atual. |
preempt |
Teste que é acionado imediatamente antes que o segmento atual seja superado. Depois que esse teste for acionado, o segmento atual irá selecionar um segmento a ser executado e o teste off-cpu será acionado no segmento atual. Em alguns casos, um segmento em uma CPU será superado, mas o segmento de maior prioridade será executado em outra CPU enquanto isso. Nessa situação, o teste preempt será acionado, mas o distribuidor não conseguirá localizar um segmento de maior prioridade para ser executado e o teste remain-cpu será acionado em vez do teste off-cpu. |
remain-cpu |
Teste que é acionado quando uma decisão de agendamento tiver sido tomada, mas o distribuidor tiver optado por continuar executando o segmento atual. A variável curcpu indica a CPU atual. A variável curlwpsinfo indica o segmento que está iniciando a execução. A variável curpsinfo descreve o processo que contém o segmento atual. |
schedctl-nopreempt |
Teste que é acionado quando um segmento é superado e depois enfileirado novamente na frente da fila de execução devido a uma solicitação de controle de preempção. Consulte schedctl_init(3C) para obter detalhes sobre controle de preempção. Assim como com preempt, off-cpu ou remain-cpu será acionado após schedctl-nopreempt. Como schedctl-nopreempt indica um re-enfileiramento do segmento atual na frente da fila de execução, é mais provável que remain-cpu seja acionado após schedctl-nopreempt do que off-cpu. A lwpsinfo_t do segmento que está sendo superado é apontada por args[0]. A psinfo_t do processo que contém o segmento é apontada por args[1]. |
schedctl-preempt |
Teste que é acionado quando um segmento que está usando o controle de preempção é, ainda sim, superado e enfileirado novamente na parte de trás da fila de execução. Consulte schedctl_init(3C) para obter detalhes sobre controle de preempção. Assim como com preempt, off-cpu ou remain-cpu será acionado após schedctl-preempt. Assim como preempt (e diferente de schedctl-nopreempt ), schedctl-preempt indica o re-enfileiramento do segmento atual na parte de trás da fila de execução. Como resultado, é mais provável que off-cpu seja acionado após schedctl-preempt do que remain-cpu. A lwpsinfo_t do segmento que está sendo superado é apontada por args[0]. A psinfo_t do processo que contém o segmento é apontada por args[1]. |
schedctl-yield |
Teste que é acionado quando um segmento que tinha o controle de preempção ativado e seu fracionamento de tempo estendido artificialmente executou o código para ceder a CPU para outros segmentos. |
sleep |
Teste que é acionado imediatamente antes de o segmento atual entrar em espera em um objeto de sincronização. O tipo do objeto de sincronização está contido no membro pr_stype da lwpsinfo_t apontada por curlwpsinfo . O endereço do objeto de sincronização está contido no membro pr_wchan da lwpsinfo_t apontada por curlwpsinfo. O significado desse endereço é um detalhe de implementação privado, mas o valor de endereço deve ser tratado como um símbolo exclusivo do objeto de sincronização. |
surrender |
Teste que é acionado quando uma CPU tiver sido instruída por outra CPU para tomar uma decisão de agendamento; geralmente porque um segmento de prioridade maior se tornou executável. |
tick |
Teste que é acionado como parte de uma contagem baseada no tique-taque do relógio. Na contagem baseada no tique-taque do relógio, a contagem de CPU é realizada examinando-se quais segmentos e processos estão sendo executados quando uma interrupção de intervalo fixo é acionada. A lwpsinfo_t que corresponde ao segmento ao qual está sendo atribuído o tempo de CPU é apontada por args[0]. A psinfo_t que corresponde ao processo que contém o segmento é apontada por args[1] . |
wakeup |
Teste que é acionado imediatamente antes do segmento atual ativar um segmento em espera em um objeto de sincronização. A lwpsinfo_t do segmento em espera é apontada por args[0]. A psinfo_t do processo que contém o segmento em espera é apontada por args[1]. O tipo do objeto de sincronização está contido no membro pr_stype da lwpsinfo_t do segmento em espera. O endereço do objeto de sincronização está contido no membro >pr_wchan da lwpsinfo_t do segmento em espera. O significado desse endereço é um detalhe de implementação privado, mas o valor de endereço deve ser tratado como um símbolo exclusivo do objeto de sincronização. |
Os tipos de argumento dos testes sched estão listados na Tabela 26–2; os argumentos são descritos na Tabela 26–1.
Tabela 26–2 Argumentos do teste sched
Teste |
args[0] |
args[1] |
args[2] |
args[3] |
---|---|---|---|---|
change-pri |
lwpsinfo_t * |
psinfo_t * |
pri_t |
— |
dequeue |
lwpsinfo_t * |
psinfo_t * |
cpuinfo_t * |
— |
enqueue |
lwpsinfo_t * |
psinfo_t * |
cpuinfo_t * |
int |
off-cpu |
lwpsinfo_t * |
psinfo_t * |
— |
— |
on-cpu |
— |
— |
— |
— |
preempt |
— |
— |
— |
— |
remain-cpu |
— |
— |
— |
— |
schedctl-nopreempt |
lwpsinfo_t * |
psinfo_t * |
— |
— |
schedctl-preempt |
lwpsinfo_t * |
psinfo_t * |
— |
— |
schedctl-yield |
lwpsinfo_t * |
psinfo_t * |
— |
— |
sleep |
— |
— |
— |
— |
surrender |
lwpsinfo_t * |
psinfo_t * |
— |
— |
tick |
lwpsinfo_t * |
psinfo_t * |
— |
— |
wakeup |
lwpsinfo_t * |
psinfo_t * |
— |
— |
Conforme indica a Tabela 26–2, muitos testes sched possuem argumentos que consistem em um ponteiro para uma lwpsinfo_t e um ponteiro para uma psinfo_t, indicando um segmento e o processo que contém o segmento, respectivamente. Essas estruturas são descritas detalhadamente em lwpsinfo_t e psinfo_t, respectivamente.
A estrutura cpuinfo_t define uma CPU. Conforme indica a Tabela 26–2, os argumentos para ambos os testes enqueue e dequeue incluem um ponteiro para uma cpuinfo_t. Além disso, a cpuinfo_t correspondente à CPU atual é apontada pela variável curcpu. A definição da estrutura de cpuinfo_t é a seguinte:
typedef struct cpuinfo { processorid_t cpu_id; /* CPU identifier */ psetid_t cpu_pset; /* processor set identifier */ chipid_t cpu_chip; /* chip identifier */ lgrp_id_t cpu_lgrp; /* locality group identifer */ processor_info_t cpu_info; /* CPU information */ } cpuinfo_t;
O membro cpu_id é o identificador de processador, conforme retornado por psrinfo(1M) e p_online(2).
O membro cpu_pset é o conjunto de processadores que contém a CPU, se houver alguma. Consulte psrset(1M) para obter mais detalhes sobre conjuntos de processadores.
O membro cpu_chip é o identificador do chipe físico. Chipes físicos podem conter várias CPUs. Consulte psrinfo(1M) para obter mais informações.
O membro cpu_lgrp é o identificador do grupo de latência associado à CPU. Consulte liblgrp(3LIB) para obter detalhes sobre grupos de latência.
O membro cpu_info é a estrutura de processor_info_t associada à CPU, conforme retornado por processor_info(2).
Uma pergunta comum que você pode fazer é quais CPUs estão executando segmentos e por quanto tempo. Você pode usar os testes on-cpu e off-cpu para responder facilmente a essa questão considerando todo o sistema, conforme mostrado no exemplo a seguir:
sched:::on-cpu { self->ts = timestamp; } sched:::off-cpu /self->ts/ { @[cpu] = quantize(timestamp - self->ts); self->ts = 0; }
Executar o script acima resultará numa saída semelhante ao exemplo seguinte:
# dtrace -s ./where.d dtrace: script './where.d' matched 5 probes ^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 |
O resultado acima mostra que na CPU 1 os segmentos tendem a ser executados por menos de 100 microssegundos em um período, ou por aproximadamente 10 milissegundos. Um intervalo evidente entre os dois clusters de dados mostrados no histograma. Talvez você também esteja interessado em saber quais CPUs estão executando um processo em particular. Você também pode usar os testes on-cpu e off-cpu para responder a essa pergunta. O script a seguir exibe quais CPUs executam um aplicativo específico durante um período de dez segundos:
#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-1sec /++x == 10/ { exit(0); } dtrace:::END { printf("CPU distribution of imapd over %d seconds:\n\n", (timestamp - start) / 1000000000); printf("CPU microseconds\n--- ------------\n"); normalize(@, 1000); printa("%3d %@d\n", @); }
A execução do script acima em um grande servidor de correio e a especificação do daemon IMAP produz um resultado similar ao exemplo a seguir:
# dtrace -s ./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 |
O Solaris leva em consideração quanto tempo um segmento está em espera ao selecionar uma CPU na qual executar o segmento: um segmento que esteja em espera por menos tempo tende a não migrar. Você pode usar os testes off-cpu e on-cpu para observar esse comportamento:
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; }
A execução do script acima por aproximadamente 30 segundos produz um resultado similar ao seguinte exemplo:
# dtrace -s ./howlong.d dtrace: script './howlong.d' matched 5 probes ^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 |
O resultado de exemplo mostra que há muito mais ocorrências de não-migração do que de migração. Além disso, quando os períodos de espera são maiores, as migrações são mais prováveis. As distribuições são evidentemente diferentes no sub-intervalo de 100 milissegundos, mas tornam-se muito similares à medida que os tempos de espera aumentam. Esse resultado poderia indicar que o tempo de espera não é calculado na decisão de agendamento quando um determinado limite é excedido.
O exemplo final usando off-cpu e on-cpu mostra como usar estes testes com o campo pr_stype para determinar por que os segmentos estão em espera e por quanto tempo:
sched:::off-cpu /curlwpsinfo->pr_state == SSLEEP/ { /* * We're sleeping. Track our sobj type. */ self->sobj = curlwpsinfo->pr_stype; self->bedtime = timestamp; } sched:::off-cpu /curlwpsinfo->pr_state == SRUN/ { self->bedtime = timestamp; } sched:::on-cpu /self->bedtime && !self->sobj/ { @["preempted"] = quantize(timestamp - self->bedtime); self->bedtime = 0; } sched:::on-cpu /self->sobj/ { @[self->sobj == SOBJ_MUTEX ? "kernel-level lock" : self->sobj == SOBJ_RWLOCK ? "rwlock" : self->sobj == SOBJ_CV ? "condition variable" : self->sobj == SOBJ_SEMA ? "semaphore" : self->sobj == SOBJ_USER ? "user-level lock" : self->sobj == SOBJ_USER_PI ? "user-level prio-inheriting lock" : self->sobj == SOBJ_SHUTTLE ? "shuttle" : "unknown"] = quantize(timestamp - self->bedtime); self->sobj = 0; self->bedtime = 0; }
A execução do script acima por vários segundos produz um resultado similar ao seguinte exemplo:
# dtrace -s ./whatfor.d dtrace: script './whatfor.d' matched 12 probes ^C kernel-level lock value -------------- Distribution ------------ count 16384 | 0 32768 |@@@@@@@@ 3 65536 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 11 131072 |@@ 1 262144 | 0 preempted value -------------- Distribution ------------ count 16384 | 0 32768 | 4 65536 |@@@@@@@@ 408 131072 |@@@@@@@@@@@@@@@@@@@@@@ 1031 262144 |@@@ 156 524288 |@@ 116 1048576 |@ 51 2097152 | 42 4194304 | 16 8388608 | 15 16777216 | 4 33554432 | 8 67108864 | 0 semaphore value -------------- Distribution ------------ count 32768 | 0 65536 |@@ 61 131072 |@@@@@@@@@@@@@@@@@@@@@@@@ 553 262144 |@@ 63 524288 |@ 36 1048576 | 7 2097152 | 22 4194304 |@ 44 8388608 |@@@ 84 16777216 |@ 36 33554432 | 3 67108864 | 6 134217728 | 0 268435456 | 0 536870912 | 0 1073741824 | 0 2147483648 | 0 4294967296 | 0 8589934592 | 0 17179869184 | 1 34359738368 | 0 shuttle value -------------- Distribution ------------ count 32768 | 0 65536 |@@@@@ 2 131072 |@@@@@@@@@@@@@@@@ 6 262144 |@@@@@ 2 524288 | 0 1048576 | 0 2097152 | 0 4194304 |@@@@@ 2 8388608 | 0 16777216 | 0 33554432 | 0 67108864 | 0 134217728 | 0 268435456 | 0 536870912 | 0 1073741824 | 0 2147483648 | 0 4294967296 |@@@@@ 2 8589934592 | 0 17179869184 |@@ 1 34359738368 | 0 condition variable value -------------- Distribution ------------ count 32768 | 0 65536 | 122 131072 |@@@@@ 1579 262144 |@ 340 524288 | 268 1048576 |@@@ 1028 2097152 |@@@ 1007 4194304 |@@@ 1176 8388608 |@@@@ 1257 16777216 |@@@@@@@@@@@@@@ 4385 33554432 | 295 67108864 | 157 134217728 | 96 268435456 | 48 536870912 | 144 1073741824 | 10 2147483648 | 22 4294967296 | 18 8589934592 | 5 17179869184 | 6 34359738368 | 4 68719476736 | 0 |
Quando uma CPU fica inativa, o distribuidor procura trabalhos enfileirados em outras CPUs (ativas). O exemplo a seguir usa o teste dequeue para entender com que freqüência os aplicativos são transferidos e por qual 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", @); }
A parte final do resultado da execução do script acima em um sistema de 4 CPUs produz um resultado similar ao seguinte exemplo:
# 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 |
Em vez de saber quais CPUs pegaram qual tarefa, talvez você queira saber as CPUs nas quais os processos e segmentos estão aguardando para ser executados. Você pode usar os testes enqueue e dequeue juntos para responder a essa questão:
sched:::enqueue { self->ts = timestamp; } sched:::dequeue /self->ts/ { @[args[2]->cpu_id] = quantize(timestamp - self->ts); self->ts = 0; }
A execução do script acima por vários segundos produz um resultado similar ao seguinte exemplo:
# 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 |
Observe os valores diferentes de zero na parte inferior do resultado de exemplo. Esses pontos de dados revelam várias instâncias em ambas as CPUs nas quais um segmento foi enfileirado para ser executado por vários segundos.
Em vez de procurar por tempos de espera, talvez você queira examinar o tamanho da fila de execução ao longo do tempo. Ao usar os testes enqueue e dequeue, você pode definir uma matriz de associação para controlar o tamanho da fila:
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]—; }
A execução do script acima por aproximadamente 30 segundos em um sistema de laptop com um processador totalmente inativo produz um resultado similar ao seguinte exemplo:
# 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 |
O resultado é aproximadamente o que você esperaria de um sistema inativo: na maior parte do tempo que um segmento executável estava enfileirado, a fila de execução estava muito curta (com três ou menos segmentos). Entretanto, como o sistema estava totalmente inativo, os pontos de dados excepcionais na parte inferior da tabela poderiam ser inesperados. Por exemplo, por que a fila de execução tinha 13 segmentos executáveis? Para explorar essa questão, você pode escrever um script em D que exiba o conteúdo da fila de execução quando a fila de execução for longa. Esse problema é complicado porque as habilitações em D não podem ser repetidas em estruturas de dados, e, portanto, não podem simplesmente ser repetidas em toda a fila de execução. Mesmo que as habilitações em D pudessem fazer isso, você deve evitar dependências nas estruturas internas de dados do kernel.
Para esse tipo de script, você ativaria os testes enqueue e dequeue e usaria matrizes de associação e de especulação. Sempre que um segmento é enfileirado, o script incrementa o tamanho da fila e registra o carimbo de data/hora em uma matriz de associação inserida pelo segmento. Você não pode usar uma variável de segmento local neste caso porque um segmento pode ser enfileirado por outro segmento. O script depois verifica se o tamanho da fila excede o máximo permitido. Caso exceda, o script iniciará uma nova especulação, e registrará o carimbo de data/hora e o novo máximo. Em seguida, quando um segmento é desenfileirado, o script compara o carimbo de data/hora do enfileiramento com o carimbo de data/hora do maior tamanho: se o segmento tiver sido enfileirado antes do carimbo de data/hora do maior tamanho, o segmento estava na fila quando o maior tamanho foi registrado. Nesse caso, o script especulativamente rastreia as informações do segmento. Depois que o kernel desenfileira o último segmento que estava enfileirado no carimbo de data/hora do maior tamanho, o script compromete os dados de especulação. Esse script é mostrado abaixo:
#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; }
A execução do script acima no mesmo laptop com um processador produz um resultado similar ao seguinte exemplo:
# 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 |
O resultado revela que as filas de execução longas são devido a muitos processos xterm executáveis. Esse experimento coincidiu com uma alteração na área de trabalho virtual, e, portanto, os resultados provavelmente são devido a algum tipo de processamento de evento X.
Em enqueue e dequeue, o exemplo final demonstrou que um crescimento súbito da fila de execução foi devido a processos xterm executáveis. Uma hipótese é que as observações resultaram de uma alteração na área de trabalho virtual. Você pode usar o teste wakeup para explorar essa hipótese determinando quem está ativando os processos xterm, e quando, conforme mostrado no exemplo a seguir:
#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 a hipótese, execute o script acima, aguardando aproximadamente cinco segundos, e alterne a área de trabalho virtual exatamente uma vez. Se o crescimento súbito de processos xterm executáveis for devido à alternância da área de trabalho virtual, o resultado deveria mostrar um crescimento súbito de atividade de ativação na marca de cinco segundos.
# dtrace -s ./xterm.d Xsun value -------------- Distribution ------------ count 4 | 0 5 |@ 1 6 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 32 7 | 0 |
O resultado mostra que o servidor X está ativando processos xterm, agrupados por volta da hora que você alternou as áreas de trabalho virtuais. Se você desejasse compreender a interação entre o servidor X e os processos xterm, poderia agregar rastreios de pilha do usuário quando o servidor X acionasse o teste wakeup.
Para se compreender o desempenho dos sistemas cliente/servidor como o sistema de janelas X, deve-se compreender os clientes em nome dos quais o servidor está realizando trabalho. Esse tipo de pergunta é difícil de ser respondida com ferramentas de análise de desempenho convencionais. Entretanto, se você tiver um modelo no qual um cliente envie uma mensagem para o servidor e entre em espera com o processamento do servidor pendente, você poderá usar o teste wakeup para determinar o cliente para o qual a solicitação está sendo realizada, conforme mostrado no exemplo a seguir:
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; }
Executar o script acima resultará numa saída semelhante ao exemplo seguinte:
dtrace -s ./xwork.d dtrace: script './xwork.d' matched 14 probes ^C xterm 9522510 soffice.bin 9912594 fvwm2 100423123 MozillaFirebird 312227077 acroread 345901577 |
Este resultado revela que a maior parte do trabalho de Xsun está sendo feita em nome dos processos acroread, MozillaFirebird e, em menor grau, fvwm2. Observe que o script só examinou ativações de objetos de sincronização de variável de condição (SOBJ_CV). Conforme descrito na Tabela 25–4, as variáveis de condição são o tipo de objeto de sincronização geralmente usado para sincronizar por razões diferentes do acesso a uma região de dados compartilhados. No caso do servidor X, um cliente irá aguardar por dados em um pipe entrando em espera em uma variável de condição.
Você pode adicionalmente usar o teste sleep junto com o teste wakeup para compreender quais aplicativos estão bloqueando quais aplicativos, e por quanto tempo, conforme mostrado no seguinte exemplo:
#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", @); }
A parte final do resultado da execução do script de exemplo por vários segundos em um sistema de área de trabalho parece com o seguinte exemplo:
# 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 |
Talvez você queira entender como e por que o MozillaFirebird está se bloqueando. Você pode modificar o script acima como mostrado no exemplo a seguir para responder a essa pergunta:
#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", @); }
A execução do script modificado por vários segundos produz um resultado similar ao seguinte exemplo:
# 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 |
Você também pode usar os testes sleep e wakeup para compreender o desempenho dos servidores de porta como o daemon do cache de serviço de nome, conforme mostrado no exemplo a seguir:
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; }
A parte final do resultado da execução do script acima em um servidor de correio grande parece com o seguinte exemplo:
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 |
Você pode estar interessado nos pontos de dados incomuns de automountd ou os pontos de dados persistentes de mais de um milissegundo de sendmail. Você pode incluir predicados adicionais no script acima para focalizar nas causas de quaisquer resultados excepcionais ou anormais.
Como o Solaris é um sistema preemptivo, os segmentos de prioridade mais alta têm precedência sobre os de prioridade mais baixa. A preempção pode induzir a uma bolha de latência significativa no segmento de prioridade mais baixa. Por isso, talvez você queira saber quais segmentos estão sendo superados por quais segmentos. O exemplo a seguir mostra como usar os testes preempt e remain-cpu para exibir estas informações:
#pragma D option quiet sched:::preempt { self->preempt = 1; } sched:::remain-cpu /self->preempt/ { self->preempt = 0; } sched:::off-cpu /self->preempt/ { /* * If we were told to preempt ourselves, see who we ended up giving * the CPU to. */ @[stringof(args[1]->pr_fname), args[0]->pr_pri, execname, curlwpsinfo->pr_pri] = count(); self->preempt = 0; } END { printf("%30s %3s %30s %3s %5s\n", "PREEMPTOR", "PRI", "PREEMPTED", "PRI", "#"); printa("%30s %3d %30s %3d %5@d\n", @); }
A execução do script acima por vários segundos em um sistema de área de trabalho produz um resultado similar ao seguinte exemplo:
# dtrace -s ./whopreempt.d ^C PREEMPTOR PRI PREEMPTED PRI # sched 60 Xsun 53 1 xterm 59 Xsun 53 1 MozillaFirebird 57 Xsun 53 1 mpstat 100 fvwm2 59 1 sched 99 MozillaFirebird 57 1 sched 60 dtrace 30 1 mpstat 100 Xsun 59 2 sched 60 Xsun 54 2 sched 99 sched 60 2 fvwm2 59 Xsun 44 2 sched 99 Xsun 44 2 sched 60 xterm 59 2 sched 99 Xsun 53 2 sched 99 Xsun 54 3 sched 60 fvwm2 59 3 sched 60 Xsun 59 3 sched 99 Xsun 59 4 fvwm2 59 Xsun 54 8 fvwm2 59 Xsun 53 9 Xsun 59 MozillaFirebird 57 10 sched 60 MozillaFirebird 57 14 MozillaFirebird 57 Xsun 44 16 MozillaFirebird 57 Xsun 54 18 |
A preempção é baseada em prioridades, por isso, talvez você queira observar alterações na prioridade ao longo do tempo. O exemplo a seguir usa o teste change-pri para exibir estas informações:
sched:::change-pri { @[stringof(args[0]->pr_clname)] = lquantize(args[2] - args[0]->pr_pri, -50, 50, 5); }
O script de exemplo captura o grau para o qual a prioridade é elevada ou diminuída e agrega por classe de agendamento. Executar o script acima resultará numa saída semelhante ao exemplo seguinte:
# dtrace -s ./pri.d dtrace: script './pri.d' matched 10 probes ^C IA value -------------- Distribution ------------ count < -50 | 20 -50 |@ 38 -45 | 4 -40 | 13 -35 | 12 -30 | 18 -25 | 18 -20 | 23 -15 | 6 -10 |@@@@@@@@ 201 -5 |@@@@@@ 160 0 |@@@@@ 138 5 |@ 47 10 |@@ 66 15 |@ 36 20 |@ 26 25 |@ 28 30 | 18 35 | 22 40 | 8 45 | 11 >= 50 |@ 34 TS value -------------- Distribution ------------ count -15 | 0 -10 |@ 1 -5 |@@@@@@@@@@@@ 7 0 |@@@@@@@@@@@@@@@@@@@@ 12 5 | 0 10 |@@@@@ 3 15 | 0 |
O resultado mostra a manipulação de prioridade da classe de agendamento Interactive (IA). Em vez de ver a manipulação de prioridade, talvez você queira ver os valores de prioridade de um determinado processo e segmento ao longo do tempo. O script a seguir usa o teste change-pri para exibir estas informações:
#pragma D option quiet BEGIN { start = timestamp; } sched:::change-pri /args[1]->pr_pid == $1 && args[0]->pr_lwpid == $2/ { printf("%d %d\n", timestamp - start, args[2]); } tick-1sec /++n == 5/ { exit(0); }
Para ver as alterações em prioridades ao longo do tempo, digite o seguinte comando em uma janela:
$ echo $$ 139208 $ while true ; do let i=0 ; done |
Em outra janela, execute o script e redirecione o resultado para um arquivo:
# dtrace -s ./pritime.d 139208 1 > /tmp/pritime.out # |
Você pode usar o arquivo /tmp/pritime.out que é gerado acima como entrada para um software de plotagem para exibir a prioridade graficamente ao longo do tempo. O gnuplot é um pacote de plotagem disponível livremente que está incluído no CD complementar do Solaris Freeware. Por padrão, o gnuplot é instalado em /opt/sfw/bin.
O Solaris usa uma contagem de CPU baseada em tique-taque, na qual uma interrupção do relógio do sistema é acionada em um intervalo fixo e atribui a utilização da CPU aos segmentos e processos em execução no momento do tique-taque. O exemplo a seguir mostra como usar o teste tick para observar essa atribuição:
# dtrace -n sched:::tick'{@[stringof(args[1]->pr_fname)] = count()}' ^C arch 1 sh 1 sed 1 echo 1 ls 1 FvwmAuto 1 pwd 1 awk 2 basename 2 expr 2 resize 2 tput 2 uname 2 fsflush 2 dirname 4 vim 9 fvwm2 10 ksh 19 xterm 21 Xsun 93 MozillaFirebird 260 |
A freqüência do relógio do sistema varia de acordo com o sistema operacional, mas geralmente vai de 25 hertz a 1024 hertz. A freqüência do relógio do sistema é ajustável, mas o padrão é 100 hertz.
O teste tick só é acionado se o relógio do sistema detecta um segmento executável. Para usar o teste tick para observar a freqüência do relógio do sistema, você deve ter um segmento que seja sempre executável. Em uma janela, crie um shell de looping conforme mostrado no exemplo a seguir:
$ while true ; do let i=0 ; done |
Em outra janela, execute o seguinte script:
uint64_t last[int]; sched:::tick /last[cpu]/ { @[cpu] = min(timestamp - last[cpu]); } sched:::tick { last[cpu] = timestamp; }
# dtrace -s ./ticktime.d dtrace: script './ticktime.d' matched 2 probes ^C 0 9883789 |
O intervalo mínimo é de 9,8 milissegundos, o que indica que a freqüência de tique-taque padrão do relógio é de 10 milissegundos (100 hertz). O mínimo observado é algo menos que 10 milissegundos devido à variação.
Uma deficiência da contagem baseada em tique-taque é que o relógio do sistema que realiza a contagem é, freqüentemente, também responsável por distribuir atividades de agendamento relacionadas ao tempo. Como resultado, se um segmento tiver que realizar alguma quantidade de trabalho a cada tique-taque do relógio (ou seja, a cada 10 milissegundos), o sistema irá contar a mais ou a menos no segmento, dependendo se a contagem for feita antes ou depois de uma atividade de agendamento de distribuição relacionada ao tempo. No Solaris, a contagem é realizada antes da distribuição relacionada ao tempo. Como resultado, o sistema irá contar a menos nos segmentos executados em intervalo regular. Se tais segmentos forem executados por menos tempo que o intervalo do tique-taque do relógio, eles podem se "esconder" eficientemente por trás do tique-taque. O exemplo a seguir mostra o grau para o qual o sistema possui tais segmentos:
sched:::tick, sched:::enqueue { @[probename] = lquantize((timestamp / 1000000) % 10, 0, 10); }
O script de exemplo resulta em duas distribuições do deslocamento de milissegundo em um intervalo de dez milissegundos: uma para o teste tick e outra para enqueue:
# dtrace -s ./tick.d dtrace: script './tick.d' matched 4 probes ^C tick value -------------- Distribution ------------ count 6 | 0 7 |@ 3 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 79 9 | 0 enqueue value -------------- Distribution ------------ count < 0 | 0 0 |@@ 267 1 |@@ 300 2 |@@ 259 3 |@@ 291 4 |@@@ 360 5 |@@ 305 6 |@@ 295 7 |@@@@ 522 8 |@@@@@@@@@@@@ 1315 9 |@@@ 337 |
O histograma de resultado chamado tick mostra que o tique-taque do relógio está sendo acionado em um deslocamento de 8 milissegundos. Se o agendamento não fosse associado ao tique-taque do relógio, o resultado de enqueue seria distribuído uniformemente no intervalo de dez milissegundos. Entretanto, o resultado mostra um pico no mesmo deslocamento de 8 milissegundos, indicando que pelo menos alguns segmentos no sistema estão sendo agendados de acordo com o tempo.
O provedor sched usa o mecanismo de estabilidade do DTrace para descrever suas estabilidades, conforme mostrado na tabela a seguir. Para obter mais informações sobre o mecanismo de estabilidade, consulte o Capítulo 39Estabilidade.
Elemento |
Estabilidade de nome |
Estabilidade de dados |
Classe de dependência |
---|---|---|---|
Provedor |
Desenvolvendo |
Desenvolvendo |
ISA |
Módulo |
Privada |
Privada |
Desconhecida |
Função |
Privada |
Privada |
Desconhecida |
Nome |
Desenvolvendo |
Desenvolvendo |
ISA |
Argumentos |
Desenvolvendo |
Desenvolvendo |
ISA |