Uma das coisas mais divertidas da vida de um administrador de sistemas é resolver um problema difícil. É ainda mais legal quando o problema é antigo e você já tentou resolvê-lo várias vezes sem sucesso. Daí, quando você consegue finalmente vencê-lo, a satisfação é enorme.
Hoje tive um desses momentos memoráveis. Tanto assim que ao invés de simplesmente mandar um email para meus colegas de trabalho resolvi relatar a solução aqui e só mandar o link pra eles. Assim eles vão poder ter razão quando disserem que o Gustavo está "se achando". :-)
Pois bem. O mistério que nos estava deixando encucados há alguns meses eram as mensagens freqüentes que apareciam no
/var/log/messages de vários servidores Linux:
May 13 16:05:02 noname automount[7655]: lookup(program): lookup for bin failed
May 13 16:05:02 noname automount[7655]: failed to mount /net/bin
Essas mensagens apareciam uma ou duas vezes por minuto, durante o dia todo, e indicavam que um ou mais processos estavam periodicamente tentando acessar o diretório
/net/bin que não existe. Como o
/net é a base de um mapa indireto do
automounter, as falhas eram reportadas por ele via
syslog.
O problema que não conseguíamos resolver era como identificar os processos que estavam acessando o diretório inexistente para podermos corrigi-los. Os logs do automounter não davam nenhuma pista útil, de modo que precisávamos de uma abordagem criativa.
O fato de os logs terem uma freqüência regular sugeria que os processos causadores pudessem estar sendo ativados via
crontab. Só que essas máquinas são servidoras e têm dezenas de usuários com crontabs definidos. Os logs do
/var/log/cron indicavam que grande parte dos crontabs iniciava comandos a cada minuto, de modo que não dava pra investigar um ou outro script especificamente.
Tentei pegar o culpado rastreando as chamadas de sistema do
daemon crond e procurando por referências ao diretório
/net/bin.
# strace -f -e trace=file -o/tmp/crond.strace -p `pidof crond`
Infelizmente, não encontrei nada, o que parecia um forte indício de que não se tratava mesmo de um processo de cron, mas eu não fiquei convencido.
Eu já tinha lido alguma coisa a respeito de ferramentas para monitorar o acesso a arquivos no Linux. Com o Google foi fácil encontrar o venerável
dnotify e seu colega mais novo
inotify. O dnotify permite monitorar o acesso aos arquivos de um diretório e o inotify é bem mais flexível. Só que o inotify não é suportado pela versão do kernel do servidor e eu desisti de instalar o dnotify pois provavelmente o tipo de acesso que os processos estavam fazendo não seria detectável mesmo por ele.
Uma idéia que parecia promissora era procurar por processos que tivessem o diretório
/net/bin presente na sua variável de ambiente PATH. Podia ser que estes processos estivessem acessando o
/net/bin como resultado do processo de busca de algum comando no PATH. Felizmente, ter a idéia foi mais difícil que implementá-la:
for e in /proc/[0-9]*/environ
do echo -n "$e: "; tr '\0' '\012' <$e | grep PATH
done | grep /net/bin
Procurar nos quase 3.000 processos do servidor demorou alguns segundos mas não devolveu resultado algum. Ou o acesso não era por causa do PATH ou os processos tinham vida curta e eu não consegui acertar em nenhum deles com esse tiro.
A próxima idéia foi importante, pois me fez descobrir algumas pistas e abriu as portas para a idéia seguinte. Se os logs eram gerados porque o
/net/bin não existia, talvez eu pudesse ver o resultado do acesso se eu o criasse. Exportei um diretório vazio de outra máquina e configurei o automounter para montá-lo como
/net/bin na servidora. Não demorou pra eu ver que ele tinha sido montado e que as mensagens de erro pararam. Já era um avanço.
A vantagem é que agora qualquer acesso ao
/net/bin deixaria um rastro de pacotes
NFS na rede. Trabalho para um analisador de pacotes como o
ethereal. Alguns minutos de captura e eu já tinha uma coleção razoável de pacotes NFS pra investigar. Consegui descobrir duas coisas. A primeira, promissora, foi que havia várias tentativas de acesso ao arquivo
/net/bin/gawk. A segunda, ruim, foi que estes acessos eram feitos por vários usuários diferentes. Eu podia identificá-los, pois suas credenciais estavam registradas nos campos
RPC dos pacotes NFS.
Daí eu pensei: se eles estão procurando o
/net/bin/gawk eu vou criar um que me avise quando for invocado. Criei um script chamado
gawk no diretório montado como
/net/bin. O script iria registrar várias informações sobre seu chamador num arquivo e dormir por 10 minutos, de modo que eu poderia identificá-lo mais facilmente. Preparei a armadilha e fiquei esperando... Nada aconteceu. Por algum motivo os processos não estavam "chamando" o
gawk falso que eu havia criado. Eu não conseguia entender porque é que algum processo procuraria o
gawk se não era para chamá-lo.
Mas a idéia de forçar o travamento dos processos que estavam acessando o
/net/bin era muito boa. Tinha que haver uma maneira de poder efetivá-la. A ficha caiu quando eu me lembrei da causa de um travamento recente no mesmo servidor: um servidor de NFS fora do ar. Agora que eu já tinha o
/net/bin montado de um servidor NFS, bastava eu desativar o serviço remoto de NFS pra que os processos que quisessem acessar o diretório ficassem suspensos num estado de
uninterruptible sleep. Tive um certo receio, pois esses travamentos devidos a problemas com servidores NFS costumam deixar os servidores num estado em que só é possível ressuscitá-los com um
reboot. Ocorre que os processos que param pelo problema com o NFS podem causar a parada de outros processos que dependam deles e assim sucessivamente. Mas como eu podia restabelecer o serviço de NFS rapidamente deveria ser possível sair de qualquer enrascada.
Parei o NFS e fiquei analisando o número de processos que iam parando no estado "D":
# ps aux | awk '$8 ~ /D/'
Pelo que me lembro, o número de processos assim chegou perto dos 400 em poucos minutos. Joguei o resultado num arquivo e reativei o NFS. Os processos travados voltaram a rodar e eu pude analisar o arquivo com calma. O que eu vi nele não fez muito sentido a princípio. Todos os processos parados ou eram instâncias de uma shell invocando o
/net/gnu/bin/gawk ou o
/net/gnu/bin/awk:
/bin/bash /net/gnu/bin/gawk ...
Preciso explicar que o
/net/gnu/bin é onde, historicamente, costumamos instalar as ferramentas livres do
Projeto GNU nas nossas máquinas Solaris. Quando começamos a instalar servidores Linux há quase 10 anos o modelo do
/net/gnu/bin não era necessário em princípio. Afinal, os sistemas Linux já vêm com todas as ferramentas do Projeto GNU instaladas nos diretórios padrão
/usr/bin e
/bin. Mas como o diretório
/net/gnu/bin já era referenciado por uma quantidade enorme de scripts e binários antigos, pra evitar o trabalho de mexer em tudo isso alguém teve a brilhante idéia de configurar o automounter das máquinas Linux para montar o diretório local
/usr/bin das máquinas como
/net/gnu/bin sempre que algum processo fizesse referência explícita ao último. (Nessas horas não adianta muito ser purista. Uma solução porca e torta que "resolva o problema" é considerada boa o suficiente. Ahem.)
Tudo bem. Que o
/net/gnu/bin/gawk era mesmo o
/usr/bin/gawk eu sabia, mas o que é que ele tinha a ver com o inexistente
/net/bin/gawk? Por que é que ao chamar o
/net/gnu/bin/gawk a shell travaria se o
/net/bin estivesse com o servidor NFS fora?
Isso não fazia nenhum sentido até que eu dei uma olhada de perto no dito cujo:
# ls -l /usr/bin/gawk
lrwxrwxrwx 1 root root 14 Dez 15 2005 /usr/bin/gawk -> ../../bin/gawk
Um link simbólico!?!? Pra que raios o
gawk é um link simbólico? Ah... o
/usr/bin/gawk está apontando para o
/bin/gawk, que é onde o binário do comando está efetivamente instalado.
Cáspita! Matei a charada. Como o link simbólico é relativo, o
/usr/bin/gawk aponta para o
/bin/gawk mas o
/net/gnu/bin/gawk acaba apontando para o
/net/bin/gawk!!!
Isso explicava o fato de eu não ter encontrado nenhuma referência direta ao
/net/bin com o strace: o PATH da shell tinha uma referência ao
/net/gnu/bin e não ao
/net/bin. O travamento ocorreu dentro do sistema operacional, na chamada ao exec, quando ele foi seguir o link simbólico.
Eu sabia que um dia eu teria uma boa razão pra dizer "bem que eu avisei" quando reclamei da gambiarra que foi o
/net/gnu/bin no Linux. Agora eu tenho. :-)
Bom, a causa do problema foi descoberta. Resta agora resolvê-lo. Idealmente, os processos que estão tentando acessar o
/net/gnu/bin deveriam ser reescritos para não tentarem. Mas algo me diz que a solução vai acabar sendo criar mais uma gambiarra. Que desta vez deverá ser montar o
/bin local dos servidores Linux no
/net/bin.
