Criação de log no kernel: APIs e implementação

Do kernel até os logs de espaço do usuário

M. Jones
Publicado em 28/Mai/2014

O uso de log para depuração é tão antigo quanto à própria computação. Os logs são úteis não apenas para compreender a operação interna de um sistema, mas também a sincronização e os relacionamentos das atividades dentro do sistema através das mensagens ordenadas por tempo, dentro do log com registro de data e hora.

Este artigo começa a explorar a criação de log no kernel observando as application programming interfaces (APIs) usadas para configurar e coletar a informação de registro (veja a Figura 1 para obter uma visualização geral da estrutura e dos componentes). Em seguida, o artigo trata do movimento de dados de log a partir do kernel até o espaço do usuário. Finalmente, o artigo irá explorar o destino dos dados de log baseados no kernel: a estrutura de gerenciamento de log no espaço do usuário com o rsyslog.

Figura 1. Ecossistema da criação de log no kernel e componentes principais

Clique para ver a imagem maior

API do Kernel

A criação de log dentro do kernel é executada usando a função printk , que é parecida com sua contraparte do espaço do usuário, printf (impressão formatada). O comando printf tem uma longa história em linguagens, mais recentemente na linguagem C , mas há muito tempo atrás, nos anos 50 e 60, na Fortran (instruções PRINT e FORMAT ), BCPL (função writf; a BCPL foi uma precursora da C), e linguagens ALGOL 68 (printf, putf).

No kernel, printk (imprimir kernel) é usada para gravar mensagens formatadas no buffer usando um formato quase idêntico à função printf. É possível localizar o formato da printk no ./linux/include/linux/kernel.h (e sua implementação no ./linux/kernel/printk.c):

int printk( const char * fmt, ... );

Esse formato indica que uma cadeia de caractere é usada para definir o texto e o formato (da mesma forma que printf) e é acompanhada por um conjunto variável de argumentos (identificados por reticências [...]).

Uma das primeiras diferenças que pode ser notada no uso de printk é que se trata mais do protocolo e menos da função. Esse recurso usa um aspecto obscuro da linguagem C para simplificar a especificação de prioridade ou de nível de mensagem. O kernel permite que cada mensagem seja classificada com um nível de registro (um dos oito que definem a gravidade da mensagem em particular). Esses níveis comunicam se o sistema se tornou inutilizável (uma mensagem emergencial), se uma condição crítica ocorreu (uma mensagem crítica) ou se a mensagem é simplesmente informativa. O código do kernel simplesmente define o nível de registro como primeiro argumento da mensagem, conforme ilustrado no exemplo a seguir de uma mensagem crítica:

printk( KERN_CRIT "Error code %08x.\n", val );

Observe que o primeiro argumento não é um argumento, já que nenhuma vírgula (,) separa o nível (KERN_CRIT) da sequência de formatações. O KERN_CRIT não é nada mais do que uma cadeia de caractere (de fato, ele representa a cadeia de caractere"<2>"; consulte a Tabela 1 para obter uma lista completa dos níveis de registro). Como parte do pré-processador, C automaticamente combina essas duas cadeias de caractere em um recurso chamado de concatenação de sequência literal. O resultado é uma única cadeia de caractere que incorpora o nível de registro e a sequência de formatações específica do usuário como uma única cadeia de caractere. Observe que se o responsável por uma chamada não fornece um nível de registro dentro do printk, um padrão do KERN_WARNING é automaticamente usado (o que significa que apenas mensagens de log do KERN_WARNING e as de prioridade mais alta serão registradas).

Tabela 1. Níveis de registro, simbólicos e usos

A chamada de printk pode ser feita de qualquer contexto no kernel. A chamada começa no ./linux/kernel/printk.c na função printk, que chama vprintk (no mesmo arquivo de origem) depois de resolver os argumentos de comprimento variável usando va_start.

A função vprintk executa várias verificações de nível de gerenciamento (procurando por recursão) e, então, captura o bloqueio para o buffer do log (__log_buf). Depois, a cadeia de caractere recebida é verificada para ver se há uma cadeia de caractere de nível de registro e, se localizada, o nível de registro é configurado de acordo com ela. Finalmente, o vprintk captura o horário atual (usando a função cpu_clock) e o converte em uma cadeia de caractere usando o sprintf (não a versão de biblioteca padrão, mas uma versão interna do kernel implementada no ./linux/lib/vsprintf.c). A cadeia de caractere passada para printk é, então, copiada no buffer do log do kernel usando uma função especial que gerencia os limites do ring (emit_log_char). No fim dessa função, uma aquisição gratuita e o release do semáforo de console são executados, o que emite a próxima mensagem de log para o console (executada dentro do release_console_sem). O tamanho do ring buffer do kernel era originalmente 4 KB, contudo, em kernels recentes é de 16 KB (e até 1 MB, dependendo da arquitetura).

Até aqui, exploramos a API usada para inserir mensagens de log no ring buffer do kernel. Agora, vamos dar uma olhada no método usado para migrar dados do kernel para o host.

Interface e criação de log no kernel

O acesso ao buffer do log é fornecido no núcleo através de uma chamada de sistema multipropósitos do syslog. Essa chamada única implementa uma variedade de ações que podem todas ser executadas em um espaço do usuário, mas, para usuários não raiz, somente uma ação pode ser executada. O protótipo para a chamada de sistema do syslog é definido no ./linux/include/linux/syslog.h; sua implementação está no ./linux/kernel/printk.c.

A chamada de syslog funciona como entrada/de saída (E/S) e controla a interface no ring buffer de mensagem de log do kernel. A partir da chamada de syslog, um aplicativo pode ler mensagens de log (parcialmente, inteiramente ou somente mensagens novas), assim como controlar o comportamento do ring buffer (limpar conteúdo, configurar o nível das mensagens que serão registradas, ativar ou desativar o console etc.) A figura 2 fornece uma ilustração gráfica da pilha de criação de log com alguns dos principais componentes discutidos.

Figura 2. Pilha de criação de log no kernel que identificam os principais componentes

Clique para ver a imagem maior

A chamada de syslog (conhecida como do_syslog, dentro do kernel no ./linux/kernel/printk.c), é uma função relativamente pequena que fornece a capacidade de ler e controlar o ring buffer do kernel. Observe que, no glibc 2.0, essa função é chamada de klogctl devido ao uso excessivo do termo syslog, que se refere a uma variedade de chamadas e aplicativos. A função de protótipo (no espaço do usuário) para syslog e klogctl é definida como:

int syslog( int type, char *bufp, int len );
int klogctl( int type, char *bufp, int len );

O argumento type comunica o comando a ser executado e é associado ao buffer opcional com seu comprimento. Alguns comandos (como o de limpeza do ring buffer) ignoram os argumentos bufp e len. Mesmo que os dois primeiros tipos de comando não executem nenhuma ação no kernel, o resto é usado para ler mensagens de log ou controlar os aspectos da criação de log. Três comandos são usados para ler mensagens de log. O comando SYSLOG_ACTION_READ é usado para bloqueio até que as mensagens de log estejam disponíveis e depois para retorná-las ao buffer fornecido. Esse comando consome as mensagens (as mensagens antigas não irão aparecer nas chamadas subsequentes para ele). O comando SYSLOG_ACTION_READ_ALL lê os últimos caracteres n do log (em que n é definido como o parâmetro 'len' passado para o klogctl). O comando SYSLOG_ACTION_READ_CLEAR executa a ação SYSLOG_ACTION_READ_ALL seguida por um comando SYSLOG_ACTION_CLEAR (limpar o ring buffer). SYSLOG_ACTION_CONSOLE ON e OFF manipulam o nível de registro para ativar ou desativar as mensagens de log no console, em que SYSLOG_CONSOLE_LEVEL permite que o responsável pela chamada defina o nível das mensagens de log que o console deve aceitar. Finalmente, SYSLOG_ACTION_SIZE_BUFFER retorna o tamanho do ring buffer do kernel, e SYSLOG_ACTION_SIZE_UNREAD retorna o número de caracteres atualmente disponíveis para leitura no ring buffer do kernel. A lista completa de comandos do SYSLOG é mostrada na Tabela 2.

Tabela 2. Comandos implementados com a chamada de sistema de syslog/klogctl

Implementado acima da camada syslog/klogctl, o sistema de arquivos kmsg proc é um caminho de E/S (implementado no ./linux/fs/proc/kmsg.c) que fornece uma interface binária para leitura de mensagens de log do buffer do kernel. Isso é comumente lido por um daemon (klogd ou rsyslogd) que consome as mensagens e as passa para rsyslog para roteamento no arquivo de log adequado (de acordo com a sua configuração).

O arquivo /proc/kmsg implementa um pequeno número de operações de arquivo que são equivalentes às operações do_syslog internas. Internamente, a chamada de open se relaciona ao SYSLOG_ACTION_OPEN e à chamada de release para SYSLOG_ACTION_CLOSE (cada uma delas é implementada como uma No Operation Performed [NOP]). A operação de pesquisa permite a espera por atividade no arquivo e chama SYSLOG_ACTION_SIZE_UNREAD para identificar o número de caracteres disponíveis para leitura. Finalmente, a operação de read faz o mapeamento para que SYSLOG_ACTION_READ consuma as mensagens de log disponíveis. Observe que o arquivo /proc/kmsg não é útil para os usuários: ele é usado por um único daemon para capturar mensagens de log e roteá-las para o arquivo de log necessário no espaço /var.

Aplicativos de espaço do usuário

O espaço do usuário fornece inúmeros pontos de acesso para leitura e gerenciamento de criação de log no kernel. Vamos começar com interfaces de níveis inferiores (como os elementos de configuração do sistema de arquivos /proc) e expandir para os aplicativos de nível superior.

O sistema de arquivos /proc exporta mais do que apenas a interface binária para acessar as mensagens de log (kmsg). Ele também apresenta vários elementos de configuração, relacionados e independentes dos que foram discutidos, através do syslog/klogctl. A listagem 1 mostra uma exploração desses parâmetros.

Listagem 1. Explorando os parâmetros de configuração printk no /proc

mtj@ubuntu:~$ cat /proc/sys/kernel/printk
4	4	1	7
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_delay
0
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_ratelimit
5
mtj@ubuntu:~$ cat /proc/sys/kernel/printk_ratelimit_burst
10

Na Listagem 1, a primeira entrada define os níveis de registros atualmente usados na API do printk. Esses níveis de registro representam o nível de registro do console, o nível de registro de mensagem padrão, o nível de registro mínimo do console e o nível de registro padrão do console. O valor printk_delay representa o número de milissegundos de atraso entre as mensagens printk (para incluir capacidade de leitura em alguns cenários). Observe que, neste caso, ele está configurado como zero e não pode ser configurado através do /proc. O printk_ratelimit define o intervalo mínimo de tempo permitido entre as mensagens (atualmente, está definido como um número de mensagens do kernel a cada cinco segundos). O número de mensagens é definido por printk_ratelimit_burst (atualmente, está definido como 10). Isso é particularmente útil se você tiver um kernel com muitas mensagens, mas um dispositivo de console com largura de banda limitada (por exemplo, sobre uma porta serial). Observe que, dentro do kernel, o limite de taxa é controlado pelo responsável pela chamada e não é implementado no printk. Um usuário de printk que deseja chamadas com limite de taxa deve chamar a função printk_ratelimit.

O comando dmesg pode também ser usado para imprimir e controlar o ring buffer do kernel. Esse comando usa a chamada do sistema de klogctl para ler o ring buffer do kernel e emiti-lo para a saída padrão (stdout). O comando também pode ser usado para limpar o ring buffer do kernel (usando a opção -c), configurar a criação de log no console (a opção-n) e definir o tamanho do buffer usado para ler as mensagens de log do kernel (opção -s). Observe que, se o tamanho do buffer não for especificado, dmesg identifica o tamanho adequado de buffer usando a operação SYSLOG_ACTION_SIZE_BUFFER no klogctl.

Finalmente, a mãe de todos os aplicativos de criação de log é o syslog, uma estrutura de criação de log padronizada que é implementada nos sistemas operacionais principais (incluindo Linux® e Berkeley Software Distribution [BSD]). syslog tem seu próprio protocolo usado para conduzir as mensagens de notificação de evento em uma variedade de protocolos de transporte (dividindo componentes em originadores, retransmissões e coletores). Em muitos casos, todos os três são implementados em um único host. Além dos vários recursos interessantes do syslog, ele especifica como as informações de criação de log são coletadas e filtradas, assim como onde armazená-las. syslog passou por inúmeras mudanças e se desenvolveu. Você provavelmente já ouviu falar do syslog, klog ou sysklogd. Nas distribuições mais recentes do Ubuntu, uma nova versão do syslog chamada de rsyslog é usada (baseada no syslog original), que se refere ao confiável e estendido syslogd.

O daemon do rsyslogd, através de seu arquivo de configuração no /etc/rsyslog.conf), entende a interface kmsg do arquivo de sistemas /proc e a usa para extrair as mensagens de criação de log do kernel. Observe que, internamente, todos os níveis de registro são gravados através do /proc/kmsg para que, em vez de o kernel definir quais níveis de registro transportar, a tarefa seja deixada para o rsyslog mesmo. As mensagens de log do kernel são, então, armazenadas no /var/log/kern.log (entre outros arquivos configurados). No /var/log, é encontrado um excesso de arquivos de log que incluem mensagens gerais e chamadas relacionadas ao sistema (/var/log/messages), log de inicialização do sistema (/var/log/boot.log), logs de autenticação (/var/log/auth.log) e outros.

Mesmo que os logs estejam disponíveis para revisão, é possível também usá-los para auditorias automatizadas e revisões mais detalhadas. Existe uma variedade de analisadores de arquivo de log para resolução de problemas ou conformidade com regulamentos de segurança e para procurar automaticamente por problemas usando técnicas como reconhecimento de padrão ou análise de correlação (mesmo em vários sistemas).

Indo além

Este artigo fornece uma reflexão rápida sobre a criação de log no kernel e aplicativos—desde a criação de mensagens de log no kernel passando pelo seu armazenamento dentro do ring buffer do kernel pelo seu transporte para o espaço do usuário através do syslog/klogctl ou /proc/kmsg, pelo seu roteamento através da estrutura de criação de log do rsyslog até seu local final de pouso na subárvore do /var/log. O Linux fornece uma estrutura completa e flexível para criação de log (tanto no kernel quanto externamente).

Recursos para download

• PDF desse conteúdo

Temas relacionados

• Leia a respeito do rsyslog (a nova estrutura de criação de log do sistema que substitui o syslog e klog) na página do manual e também no site de wiki.
• O Ubuntu mantém uma página útil sobre criação de log com foco no rsyslog. Este White Paper fornece uma introdução detalhada à criação de log e ao rsyslog, incluindo configuração e redes complexas de criação de log com diversos hosts.
• A man page do syslog(2) fornece uma ótima introdução ao syslog(2) e suas várias opções e configurações.
• A função printk baseia-se em um recurso da linguagem C chamada de concatenação de sequência literal. Esta página sobre a linguagem C na Wikipédia apresenta essa técnica.
• O protocolo syslog é atualmente um protocolo padronizado através do processo Request for Comments (RFC) da Internet Engineering Task Force. Leia a respeito do syslog RFC 5424.
• A análise do arquivo de log é um tópico muito procurado no learning de máquinas e em ferramentas de monitoramento. Leia mais a respeito da análise geral de log na Wikipédia e sobre uma ferramenta de monitoramento de arquivos de log chamada Swatch no SourceForge.
• Na zona Linux do developerWorks, encontre centenas de artigos de instruções e tutoriais, assim como downloads, fóruns de discussão e uma boa quantidade de outros recursos para desenvolvedores e administradores de Linux.
• Avalie os produtos da IBM da melhor maneira para você: faça um download de uma versão de avaliação, experimente um produto on-line, use um produto em um ambiente de nuvem ou passe algum tempo no ambiente de simulação da SOA aprendendo como implementar a Arquitetura Orientada a Serviços de maneira eficiente.
• Siga o developerWorks no Twitter ou inscreva-se em um feed dos tweets do Linux no developerWorks.