[FUG-BR] dtrace
Patrick Tracanelli
eksffa em freebsdbrasil.com.br
Qua Maio 31 10:47:03 BRT 2006
Thadeu Penna wrote:
> On 5/30/06, Eduardo B Ribeiro <asdrub em openit.com.br> wrote:
>
>>Em Ter, 2006-05-30 às 23:20 -0300, Thadeu Penna escreveu:
>>
>>> 1. How many times does a FreeBSD
>>>buildworld/buildkernel/installkernel open each file and what are the
>>>file names?
>>> 2. What processes fork during a buildworld and how many times?
>>> 3. Quantize the size of reads during a buildworld.
>>> 4. Reading fields in the current thread structure.
>>>
>>>Não sei que informação útil tirar de nenhum dos quatro exemplos
>>>acima :(
>>
>>Olá,
>>
>>Imagine que o exemplo refere-se a uma ferramenta muito interna do
>>sistema (build) e que os dados extraídos ali certamente são de mais
>>valia para quem está trabalhando com o sistema de rebuild do freebsd
>>(debugando e/ou tentanto otimizá-lo).
>>No entanto, se vc abstrair os exemplos, veja que poderá fazer o mesmo
>>com qquer outra aplicação, tipo: algo que vc esteja desenvolvendo e que
>>não esteja tendo o desempenho esperado em algum momento crítico de uso
>>no seu cliente. Algum gargalo que costuma ser sempre difícil
>>identificar.
>>Nunca teve um caso daqueles em que o problema só acontece quando o
>>"administrador não está", ou mesmo em algum determinado tipo de uso da
>>ferramenta sob determinada condição ou estado do sistema/rede e tal?
>>Bem, um debug dinâmico iria facilitar bastante, indo certamente além do
>>que o loglevel de uma determinada aplicação poderá lhe informar, pois
>>trata de operações e estados subjacentes às operações no nível do OS. A
>>meu ver, isso facilitaria muuuito o dia-a-dia de qualquer administrador
>>que tenha alguns dos famosos "clientes chatos", não?
>>
>
>
> Está ficando mais claro mas eu acho difícil que um administrador sem
> noção de programação consiga retirar alguma informação importante
> rapidamente (quantos admins sabem tirar informações do strace ? ;) .
> Eu acho que interessa mais a desenvolvedores que admins: para
> verificar gargalos no desenvolvimento, o gprof funciona bem pra mim,
> mas o dtrace parece útil pois fornece informações em condições de
> stress.
Ai entra um ponto interessante. Em geral desenvolvedores tem ferramentas
mais interessantes como os basicos depuradores pra encontrar esse tipo
de problema, e outras pra testar performance como o profiler (gprof) que
voce mesmo mencionou. Mas o poder do dtrace e extender essas analises do
desenvolvedor e coloca-las disponivel pra administradores, que tenham
nocoes basicas de como o sistema operacional se comporta, nao
necessariamente ligado ao desenvolvimento. Por exemplo, saber o que uma
syscall faz, reconhecer argumentos de descritores de arquivos. Sao
referencias que podem ser encontradas nas proprias sessoes de paginas de
manuais de interface do kernel, em qualquer FreeBSD.
Dar ao usuario comum/administrador o recurso pra acompanhar
sequencialmente cada uma dessas chamadas, os dados de entrada e a saida
gerada, e onde mora o poder do dtrace.
Na pratica voce consegue com isso identificar modulos de kernel atuando
de forma ofuscada no seu sistema, tipico de root kit, consegue
identificar se nada no proprio kernel esta interferindo no comportamento
de uma aplicacao de userland, como ps(1), netstat(1) ou sshd(1).
Consegue saber porque um processo entra em um estado especifico, e
demora pra sair dele. Digamos Giant ou UFS, mesmo em programas nao muito
modulares (aqueles que um mesmo programa realiza diversas funcoes, e
voce nunca sabe que tipo de isntrucao ele esta naquele momento
desenvolvendo).
Em referencias de seguranca como SANS Security e certificacoes de
seguranca, usa-se esse tipo de ferramenta pra analises de Pen Test
(testes de penetracao) onde pode-se observar comportamentos falhos de
aplicacoes sob determinadas circunstancias.
O famoso problema do telnetd do FreeBSD na serie 4 foi descoberto assim,
e olha que ainda nem era o dtrace...
Talvez seja mais facil visualizar, do que ficar imaginando, proponho o
seguinte, ative seu sshd, se ja nao tiver ativado, por exemplo
/usr/sbin/sshd -4
Ache o PID dele, e use o ktrace:
ktrace -p <PID>
Exemplo:
ktrace -p 492
Quando fizer isso, o trace de cada chamada da aplicacao sera documentada
(ou ao menos das chamadas que o ktrace suporta) no arquivo ktrace.out no
mesmo diretorio que voce executou, ou onde preferir, se usar a opcao -t
(por exemplo -t /tmp/sshd_ktrace.out).
Faca uma sessao ssh local (ssh 0). Veja que apareceram dados no seu
trace file (trfile, ktrace.out no caso). Para ter uma visualizacao
humana dessas informacoes use o kdump (kernel trace dump):
Por exemplo:
(eksffa em claire)~# kdump -f ktrace.out
492 sshd RET select 1
492 sshd CALL accept(0x3,0xbfbfede0,0xbfbfdf58)
492 sshd RET accept 4
492 sshd CALL fcntl(0x4,0x3,0)
492 sshd RET fcntl 6
492 sshd CALL fcntl(0x4,0x4,0x2)
492 sshd RET fcntl 0
492 sshd CALL pipe
492 sshd RET pipe 5
492 sshd CALL socketpair(0x1,0x1,0,0xbfbfdf60)
492 sshd RET socketpair 0
492 sshd CALL fork
492 sshd RET fork 836/0x344
492 sshd CALL close(0x6)
492 sshd RET close 0
492 sshd CALL write(0x7,0xbfbfde80,0x5)
492 sshd GIO fd 7 wrote 5 bytes
0x0000 0000 009d 00
|.....|
492 sshd RET write 5
492 sshd CALL write(0x7,0x807d000,0x9c)
492 sshd GIO fd 7 wrote 156 bytes
0x0000 0000 0094 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a
0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a |....................................|
0x0024 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a
0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a |....................................|
0x0048 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a
0a0a 0a0a 0a0a 0a0a 0a0a 0a0a 0a0a |....................................|
0x006c 0a0a 0a0a 5375 6273 7973 7465 6d09 7366 7470 092f 7573
722f 6c69 6265 7865 632f 7366 7470 |....Subsystem.sftp./usr/libexec/sftp|
0x0090 2d73 6572 7665 720a 0000 0000
|-server.....|
492 sshd RET write 156/0x9c
492 sshd CALL close(0x7)
492 sshd RET close 0
492 sshd CALL close(0x8)
492 sshd RET close 0
492 sshd CALL gettimeofday(0xbfbfde40,0)
492 sshd RET gettimeofday 0
492 sshd CALL getpid
492 sshd RET getpid 492/0x1ec
492 sshd CALL open(0x28337ebf,0,0)
492 sshd NAMI "/dev/urandom"
492 sshd RET open 6
492 sshd CALL read(0x6,0xbfbfde4c,0x74)
492 sshd GIO fd 6 read 116 bytes
0x0000 634c 5f63 4a0f 7ea0 052f 1d32 68ac 19da 2701 cd50 e615
ce39 11d4 72ec 9078 2b49 d06f db83 |cL_cJ.~../.2h...'..P...9..r..x+I.o..|
0x0024 f22f 29cc f3bf 912b 0805 ae2b 751f 6e1f 816e 93c4 59e4
30bd f34a 1f42 6503 88de f44a 1235 |./)....+...+u.n..n..Y.0..J.Be....J.5|
0x0048 5571 c9ce f242 2d9c e485 d5ae 1d8e ff70 cac9 ca56 690c
cacc 7f9d 825a 0c11 efca ba7e 9dc8 |Uq...B-........p...Vi......Z.....~..|
0x006c 101d b6c8 46fb ae57
|....F..W|
492 sshd RET read 116/0x74
492 sshd CALL close(0x6)
492 sshd RET close 0
492 sshd CALL close(0x4)
492 sshd RET close 0
492 sshd CALL select(0x6,0x80788f0,0,0,0)
492 sshd RET select -1 errno 4 Interrupted system call
492 sshd PSIG SIGCHLD caught handler=0x804e9b4 mask=0x0 code=0x0
492 sshd CALL wait4(0xffffffff,0xbfbfdb8c,0x1,0)
492 sshd RET wait4 836/0x344
492 sshd CALL wait4(0xffffffff,0xbfbfdb8c,0x1,0)
492 sshd RET wait4 -1 errno 10 No child processes
492 sshd CALL sigaction(0x14,0,0xbfbfdb10)
492 sshd RET sigaction 0
492 sshd CALL sigreturn(0xbfbfdbc0)
492 sshd RET sigreturn JUSTRETURN
492 sshd CALL select(0x6,0x80788f0,0,0,0)
492 sshd RET select 1
492 sshd CALL close(0x5)
492 sshd RET close 0
492 sshd CALL select(0x6,0x80788f0,0,0,0)
Ai esta, e pra isso que serve esse tipo de ferramenta. No exemplo acima
qualquer um consegue visualizar syscalls e chamadas distintas, inclusive
chamadas de referencia a bibliotecas.
Voce consegue observar o sshd abrindo pipe, abrindo socket, fazendo fork
dele mesmo e criando uma isntancia dele mesmo desprivilegiada, consegue
visualizar onde eh feita a chamada (CALL) e que resultado ela retorna
(ret), consegue saber que o cliente nao conhecia a chave SSH em questao
e, e que essa chave foi informada ao cliente pra ver se ele aceita ou
nao a sessao com essa chave, viu abrindo o device /dev/urandom, carregar
o sftp, consegue ver referencia a descritores de arquivos... conseguiria
por exemplo saber quem eh o fd 6 (file descriptor 6) se em paralelo
usasse o "fstat" e ver foram lido 116 bytes desse arquivo... consegue
ver o processo filho (forked) saindo, e visualizar se ele saiu
graciosamente oi foi morto/interrompido, e em todos esses casos
visualizar detalhes dessa saida, como os dados de handler, posicao de
memoria... e por ultimo ve o sshd pai voltando pro seu estado mais
comum, ficar em "select", e ai com um simples "top"
492 root 1 96 0 3388K 2552K select 0:00 0.00% sshd
Ta la, o mesmo carinha, em "select".
Tai, nao tem que ser developer, basta ser um sysadmin atento, pra
conseguir tirar bons proveitos de ferremtnas de trace. E o que nao
soubermos, bem vindo a realidade que o FreeBSD e um sistema fabuloso que
se auto documenta de forma muito satisfatoria, por exemplo, o que sera
que gettimeofday eh e faz? Ah o nome eh obvio, mas vamos ver:
man gettimeofday
Opa, e wait4? que raio eh isso?
man wait4
The wait4() system call provides a more general interface for programs
that need to wait for certain child processes, that need resource uti-
lization statistics accumulated by child processes, or that require
options. The other wait functions are implemented using wait4().
Tai, um exemplo simples e que mostra o poder desse tipo de ferramenta.
Detalhe, ktrace existe desde o 4.4BSD, obviamente foi melhorado ao longo
dos anos e no FreeBSD hj e uma ferramenta bem interessante ja. Agora
imagine o ktrace multiplicado por 100 em termos de detalhes das chamadas
sendo feitas... e de numero de chamadas e alocacoes que podem ser
acompanhadas. Este sera o dtrace quando estiver totalmente portado.
Dai da pra ter uma boa ideia do poder da ferramenta.
--
Patrick Tracanelli
FreeBSD Brasil LTDA.
(31) 3281-9633 / 3281-3547
316601 em sip.freebsdbrasil.com.br
http://www.freebsdbrasil.com.br
"Long live Hanin Elias, Kim Deal!"
Mais detalhes sobre a lista de discussão freebsd