Obtendo o máximo de seus arquivos de log PHP: um guia prático

Pode-se dizer com razão que os logs são uma das ferramentas mais subestimadas e subutilizadas à disposição de um desenvolvedor php freelance. Apesar da riqueza de informações que eles podem oferecer, não é incomum que os logs sejam o último lugar que um desenvolvedor procura ao tentar resolver um problema.

Na verdade, os arquivos de log do PHP devem, em muitos casos, ser o primeiro lugar para procurar pistas quando ocorrerem problemas. Muitas vezes, as informações que eles contêm podem reduzir significativamente a quantidade de tempo gasto puxando o cabelo tentando rastrear um inseto retorcido.

Mas talvez ainda mais importante, com um pouco de criatividade e premeditação, seus arquivos de log podem ser aproveitados para servir como uma fonte valiosa de informações e análises de uso. O uso criativo de arquivos de log pode ajudar a responder a perguntas como: Quais navegadores são mais usados ​​para visitar meu site? Qual é o tempo médio de resposta do meu servidor? Qual foi a porcentagem de solicitações para a raiz do site? Como o uso mudou desde que implantamos as atualizações mais recentes? E muito, muito mais.

Este artigo fornece várias dicas sobre como configurar seus arquivos de log, bem como processar as informações que eles contêm, a fim de maximizar o benefício que eles fornecem.

Embora este artigo se concentre tecnicamente no log para desenvolvedores PHP, muitas das informações aqui apresentadas são bastante independentes de tecnologia e também são relevantes para outras linguagens e pilhas de tecnologia.

Nota: Este artigo pressupõe familiaridade básica com o shell Unix. Para aqueles que não possuem esse conhecimento, é fornecido um Apêndice que apresenta alguns dos comandos necessários para acessar e ler arquivos de log em um sistema Unix.

Nosso projeto de exemplo de arquivo de log PHP

Como um projeto de exemplo para fins de discussão neste artigo, usaremos o Symfony Standard como um projeto de trabalho e o configuraremos no Debian 7 Wheezy com rsyslogd , nginx e PHP-FPM .

 composer create-project symfony/framework-standard-edition my "2.6.*"

Isso nos dá rapidamente um projeto de teste funcional com uma boa interface do usuário.

Dicas para configurar seus arquivos de log

Aqui estão algumas dicas sobre como configurar seus arquivos de log para ajudar a maximizar seu valor.

Configuração do registro de erros

Os logs de erros representam a forma mais básica de log; ou seja, capturar informações e detalhes adicionais quando ocorrerem problemas. Então, em um mundo ideal, você gostaria que não houvesse erros e que seus logs de erros estivessem vazios. Mas quando ocorrem problemas (como invariavelmente acontecem), seus logs de erros devem ser uma das primeiras paradas que você faz em sua trilha de depuração.

Os logs de erros geralmente são muito fáceis de configurar.

Por um lado, todas as mensagens de erro e travamento podem ser registradas no log de erros exatamente no mesmo formato em que seriam apresentadas a um usuário. Com alguma configuração simples, o usuário final nunca precisará ver esses traços de erro feios em seu site, enquanto os devops ainda poderão monitorar o sistema e revisar essas mensagens de erro em todos os seus detalhes sangrentos. Veja como configurar esse tipo de log no PHP:

 log_errors = On error_reporting = E_ALL error_log = /path/to/my/error/log

Outras duas linhas que são importantes para incluir em um arquivo de log para um site ativo, para evitar que níveis sangrentos de detalhes de erro sejam apresentados aos usuários, são:

 display_errors = Off display_startup_errors = Off

Configuração do Log do Sistema ( syslog )

Existem muitas implementações geralmente compatíveis do daemon syslog no mundo de código aberto, incluindo:

• syslogd e sysklogd – mais frequentemente vistos em sistemas da família BSD, CentOS, Mac OS X e outros
• syslog-ng – padrão para builds modernos do Gentoo e SuSE
• rsyslogd – amplamente utilizado nas famílias de sistemas operacionais Debian e Fedora

(Observação: neste artigo, usaremos rsyslogd para nossos exemplos.)

A configuração básica do syslog geralmente é adequada para capturar suas mensagens de log em um arquivo de log de todo o sistema (normalmente /var/log/syslog ; também pode ser /var/log/messages ou /var/log/system.log dependendo da distribuição você está usando).

O log do sistema fornece vários recursos de log, oito dos quais ( LOG_LOCAL0 a LOG_LOCAL7 ) são reservados para projetos implantados pelo usuário. Aqui, por exemplo, é como você pode configurar LOG_LOCAL0 para gravar em 4 arquivos de log separados, com base no nível de log (ou seja, erro, aviso, informação, depuração):

 # /etc/rsyslog.d/my.conf local0.err /var/log/my/err.log local0.warning /var/log/my/warning.log local0.info -/var/log/my/info.log local0.debug -/var/log/my/debug.log

Agora, sempre que você gravar uma mensagem de log no recurso LOG_LOCAL0 , as mensagens de erro irão para /var/log/my/err.log , as mensagens de aviso irão para /var/log/my/warning.log , e assim por diante. Observe, no entanto, que o daemon syslog filtra mensagens para cada arquivo com base na regra “deste nível e superior”. Assim, no exemplo acima, todas as mensagens de erro aparecerão em todos os quatro arquivos configurados, mensagens de aviso aparecerão em todos, exceto no log de erros, mensagens de informação aparecerão nos logs de informação e depuração, e mensagens de depuração irão apenas para debug.log .

Uma nota importante adicional; Os sinais - antes dos arquivos de nível de informação e depuração no exemplo de arquivo de configuração acima indicam que as gravações nesses arquivos devem ser executadas de forma assíncrona (já que essas operações não são bloqueantes). Isso normalmente é bom (e até recomendado na maioria das situações) para logs de informações e depuração, mas é melhor que as gravações no log de erros (e provavelmente também no log de avisos) sejam síncronas.

Para encerrar um nível menos importante de log (por exemplo, em um servidor de produção), você pode simplesmente redirecionar mensagens relacionadas para /dev/null (ou seja, para lugar nenhum):

 local0.debug /dev/null # -/var/log/my/debug.log

Uma personalização específica que é útil, especialmente para dar suporte a algumas das análises de arquivos de log do PHP que discutiremos mais adiante neste artigo, é usar tab como o caractere delimitador nas mensagens de log. Isso pode ser feito facilmente adicionando o seguinte arquivo em /etc/rsyslog.d :

 # /etc/rsyslog.d/fixtab.conf $EscapeControlCharactersOnReceive off

E, finalmente, não se esqueça de reiniciar o daemon syslog depois de fazer as alterações de configuração para que elas entrem em vigor:

 service rsyslog restart

Configuração de log do servidor

Ao contrário dos logs de aplicativos e logs de erros nos quais você pode gravar, os logs do servidor são gravados exclusivamente pelos daemons de servidor correspondentes (por exemplo, servidor web, servidor de banco de dados etc.) em cada solicitação. O único “controle” que você tem sobre esses logs é na medida em que o servidor permite que você configure sua funcionalidade de log. Embora possa haver muito o que filtrar nesses arquivos, eles geralmente são a única maneira de ter uma noção clara do que está acontecendo “nos bastidores” com seu servidor.

Vamos implantar nosso aplicativo de exemplo Symfony Standard no ambiente nginx com backend de armazenamento MySQL. Aqui está a configuração do host nginx que usaremos:

 server { server_name my.log-sandbox; root /var/www/my/web; location / { # try to serve file directly, fallback to app.php try_files $uri /app.php$is_args$args; } # DEV # This rule should only be placed on your development environment # In production, don't include this and don't deploy app_dev.php or config.php location ~ ^/(app_dev|config)\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; } # PROD location ~ ^/app\.php(/|$) { fastcgi_pass unix:/var/run/php5-fpm.sock; fastcgi_split_path_info ^(.+\.php)(/.*)$; include fastcgi_params; fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name; fastcgi_param HTTPS off; # Prevents URIs that include the front controller. This will 404: # http://domain.tld/app.php/some-path # Remove the internal directive to allow URIs like this internal; } error_log /var/log/nginx/my_error.log; access_log /var/log/nginx/my_access.log; }

Com relação às duas últimas diretivas acima: access_log representa o log geral de requisições, enquanto error_log é para erros e, assim como nos logs de erros da aplicação, vale a pena configurar um monitoramento extra para ser alertado sobre problemas para que você possa reagir rapidamente.

Nota: Este é um arquivo de configuração nginx intencionalmente simplificado que é fornecido apenas para fins de exemplo. Ele quase não presta atenção à segurança e desempenho e não deve ser usado como está em nenhum ambiente “real”.

Isso é o que obtemos em /var/log/nginx/my_access.log depois de digitar http://my.log-sandbox/app_dev.php/ no navegador e pressionar Enter .

 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /app_dev.php/ HTTP/1.1" 200 6715 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/body.css HTTP/1.1" 200 6657 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/framework/css/structure.css HTTP/1.1" 200 1191 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/css/demo.css HTTP/1.1" 200 2204 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-quick-tour.gif HTTP/1.1" 200 4770 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-demo.gif HTTP/1.1" 200 4053 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /bundles/acmedemo/images/welcome-configure.gif HTTP/1.1" 200 3530 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:28 +0300] "GET /favicon.ico HTTP/1.1" 200 6518 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36" 192.168.56.1 - - [26/Apr/2015:16:13:30 +0300] "GET /app_dev.php/_wdt/e50d73 HTTP/1.1" 200 13265 "http://my.log-sandbox/app_dev.php/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_10_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.90 Safari/537.36"

Isso mostra que, para servir uma página, o navegador realmente realiza 9 chamadas HTTP. 7 deles, no entanto, são solicitações de conteúdo estático, que são simples e leves. No entanto, eles ainda consomem recursos de rede e é isso que pode ser otimizado usando vários sprites e técnicas de minificação.

Embora essas otimizações devam ser discutidas em outro artigo, o que é relevante aqui é que podemos registrar solicitações para conteúdo estático separadamente usando outra diretiva de location para eles:

 location ~ \.(jpg|jpeg|gif|png|ico|css|zip|tgz|gz|rar|bz2|pdf|txt|tar|wav|bmp|rtf|js)$ { access_log /var/log/nginx/my_access-static.log; }

Lembre-se de que a location do nginx executa uma correspondência simples de expressões regulares, para que você possa incluir quantas extensões de conteúdo estático você espera despachar em seu site.

Analisar esses logs não é diferente de analisar os logs do aplicativo.

Outros registros que merecem destaque

Dois outros logs do PHP que valem a pena mencionar são o log de depuração e o log de armazenamento de dados.

O log de depuração

Outra coisa conveniente sobre os logs do nginx é o log de depuração. Podemos ativá-lo substituindo a linha error_log da configuração pelo seguinte (requer que o módulo de depuração nginx esteja instalado):

 error_log /var/log/nginx/my_error.log debug;

A mesma configuração se aplica ao Apache ou a qualquer outro servidor web que você use.

E, aliás, os logs de depuração não estão relacionados aos logs de erros, embora estejam configurados na diretiva error_log .

Embora o log de depuração possa realmente ser detalhado (uma única solicitação nginx, por exemplo, gerou 127 KB de dados de log!), ele ainda pode ser muito útil. Percorrer um arquivo de log pode ser complicado e tedioso, mas muitas vezes pode fornecer rapidamente pistas e informações que ajudam muito a acelerar o processo de depuração.

Em particular, o log de depuração pode realmente ajudar na depuração das configurações do nginx, especialmente nas partes mais complicadas, como correspondência de location e cadeias de rewrite .

Obviamente, os logs de depuração nunca devem ser habilitados em um ambiente de produção. A quantidade de espaço que eles usam também e a quantidade de informações que eles armazenam significam muita carga de E/S em seu servidor, o que pode degradar significativamente o desempenho de todo o sistema.

Registros de armazenamento de dados

Outro tipo de log do servidor (útil para depuração) são os logs de armazenamento de dados. No MySQL, você pode ativá-los adicionando estas linhas:

 [mysqld] general_log = 1 general_log_file = /var/log/mysql/query.log

Esses logs simplesmente contêm uma lista de consultas executadas pelo sistema enquanto atendem a solicitações de banco de dados em ordem cronológica, o que pode ser útil para várias necessidades de depuração e rastreamento. No entanto, eles não devem permanecer habilitados em sistemas de produção, pois gerarão carga de E/S desnecessária extra, o que afeta o desempenho.

Gravando em seus arquivos de log

O próprio PHP fornece funções para abrir, gravar e fechar arquivos de log ( openlog() , syslog() e closelog() , respectivamente).

Existem também inúmeras bibliotecas de log para o desenvolvedor PHP, como Monolog (popular entre os usuários do Symfony e Laravel), bem como várias implementações específicas de framework, como os recursos de log incorporados ao CakePHP. Geralmente, bibliotecas como Monolog não apenas envolvem chamadas syslog() , mas também permitem o uso de outras funcionalidades e ferramentas de back-end.

Aqui está um exemplo simples de como gravar no log:

 <?php openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'It works!');

Nossa chamada aqui para openlog :

• configura o PHP para anexar um identificador exclusivo a cada mensagem de log do sistema durante a vida útil do script
• configura-o para atrasar a abertura da conexão syslog até que a primeira chamada syslog() ocorra
• define LOG_LOCAL0 como o recurso de registro padrão

Veja como ficaria o conteúdo do arquivo de log depois de executar o código acima:

 # cat /var/log/my/info.log Mar 2 00:23:29 log-sandbox 54f39161a2e55: It works!

Maximizando o valor de seus arquivos de log PHP

Agora que estamos bem com a teoria e o básico, vamos ver o quanto podemos obter dos logs fazendo o mínimo de alterações possível em nosso projeto Symfony Standard de amostra.

Primeiro, vamos criar os scripts src/log-begin.php (para abrir e configurar corretamente nossos logs) e src/log-end.php (para registrar informações sobre a conclusão bem-sucedida). Observe que, para simplificar, apenas gravaremos todas as mensagens no log de informações.

 # src/log-begin.php <?php define('START_TIME', microtime(true)); openlog(uniqid(), LOG_ODELAY, LOG_LOCAL0); syslog(LOG_INFO, 'BEGIN'); syslog(LOG_INFO, "URI\t{$_SERVER['REQUEST_URI']}"); $browserHash = substr(md5($_SERVER['HTTP_USER_AGENT']), 0, 7); syslog(LOG_INFO, "CLIENT\t{$_SERVER['REMOTE_ADDR']}\t{$browserHash}"); <br /> # src/log-end.php <?php syslog(LOG_INFO, "DISPATCH TIME\t" . round(microtime(true) - START_TIME, 2)); syslog(LOG_INFO, 'END');

E vamos exigir esses scripts em app.php :

 <?php require_once(dirname(__DIR__) . '/src/log-begin.php'); syslog(LOG_INFO, "MODE\tPROD"); # original app.php contents require_once(dirname(__DIR__) . '/src/log-end.php');

Para o ambiente de desenvolvimento, queremos exigir esses scripts em app_dev.php também. O código para fazer isso seria o mesmo acima, exceto que definiríamos o MODE como DEV em vez de PROD .

Também queremos rastrear quais controladores estão sendo invocados, então vamos adicionar mais uma linha em Acme\DemoBundle\EventListener\ControllerListener , logo no início do método ControllerListener::onKernelController() :

 syslog(LOG_INFO, "CONTROLLER\t" . get_class($event->getController()[0]));

Observe que essas alterações totalizam apenas 15 linhas extras de código, mas podem gerar coletivamente uma riqueza de informações.

Analisando os dados em seus arquivos de log

Para começar, vamos ver quantas solicitações HTTP são necessárias para atender a cada carregamento de página.

Aqui estão as informações nos registros de uma solicitação, com base na maneira como configuramos nosso registro:

 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: BEGIN Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ Mar 3 12:04:20 log-sandbox 54f58724b1ccc: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:20 log-sandbox 54f58724b1ccc: MODE DEV Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController Mar 3 12:04:25 log-sandbox 54f58724b1ccc: DISPATCH TIME 4.51 Mar 3 12:04:25 log-sandbox 54f58724b1ccc: END Mar 3 12:04:25 log-sandbox 54f5872967dea: BEGIN Mar 3 12:04:25 log-sandbox 54f5872967dea: URI /app_dev.php/_wdt/59b8b6 Mar 3 12:04:25 log-sandbox 54f5872967dea: CLIENT 192.168.56.1 1b101cd Mar 3 12:04:25 log-sandbox 54f5872967dea: MODE DEV Mar 3 12:04:28 log-sandbox 54f5872967dea: CONTROLLER Symfony\Bundle\WebProfilerBundle\Controller\ProfilerController Mar 3 12:04:29 log-sandbox 54f5872967dea: DISPATCH TIME 4.17 Mar 3 12:04:29 log-sandbox 54f5872967dea: END

Agora sabemos que cada carregamento de página é servido com duas solicitações HTTP.

Na verdade, há dois pontos que valem a pena mencionar aqui. Primeiro, as duas solicitações por carregamento de página são para usar o Symfony no modo dev (o que fiz ao longo deste artigo). Você pode identificar chamadas de modo dev pesquisando por blocos de URL /app-dev.php/ . Segundo, digamos que cada carregamento de página seja servido com duas requisições subsequentes para o aplicativo Symfony. Como vimos anteriormente nos logs de acesso do nginx, na verdade existem mais chamadas HTTP, algumas das quais são para conteúdo estático.

OK, agora vamos navegar um pouco no site de demonstração (para construir os dados nos arquivos de log) e vamos ver o que mais podemos aprender com esses logs.

Quantas solicitações foram atendidas no total desde o início do arquivo de log?

 # grep -c BEGIN info.log 10

Algum deles falhou (o script foi encerrado sem chegar ao fim)?

 # grep -c END info.log 10

Vemos que o número de registros BEGIN e END coincidem, então isso nos diz que todas as chamadas foram bem-sucedidas. (Se o script PHP não tivesse sido concluído com sucesso, ele não teria alcançado a execução do script src/log-end.php .)

Qual foi a porcentagem de solicitações para a raiz do site?

 # `grep -cE "\s/app_dev.php/$" info.log` 2

Isso nos diz que houve 2 carregamentos de página da raiz do site. Como aprendemos anteriormente que (a) há 2 solicitações para o aplicativo por carregamento de página e (b) houve um total de 10 solicitações HTTP, a porcentagem de solicitações para a raiz do site foi de 40% (ou seja, 2x2/10).

Qual classe de controlador é responsável por atender solicitações à raiz do site?

 # grep -E "\s/$|\s/app_dev.php/$" info.log | head -n1 Mar 3 12:04:20 log-sandbox 54f58724b1ccc: URI /app_dev.php/ # grep 54f58724b1ccc info.log | grep CONTROLLER Mar 3 12:04:23 log-sandbox 54f58724b1ccc: CONTROLLER Acme\DemoBundle\Controller\WelcomeController

Aqui usamos o ID exclusivo de uma solicitação para verificar todas as mensagens de log relacionadas a essa solicitação única. Assim, pudemos determinar que a classe do controlador responsável por atender solicitações à raiz do site é Acme\DemoBundle\Controller\WelcomeController .

Quais clientes com IPs da sub-rede 192.168.0.0/16 acessaram o site?

 # grep CLIENT info.log | cut -d":" -f4 | cut -f2 | sort | uniq 192.168.56.1

Como esperado neste caso de teste simples, apenas meu computador host acessou o site. Este é, obviamente, um exemplo muito simplista, mas a capacidade que ele demonstra (de poder analisar as origens do tráfego para o seu site) é obviamente bastante poderosa e importante.

Quanto do tráfego do meu site foi proveniente do FireFox?

Tendo 1b101cd como o hash do meu Firefox User-Agent, posso responder a esta pergunta da seguinte forma:

 # grep -c 1b101cd info.log 8 # grep -c CLIENT info.log 10

Resposta: 80% (ou seja, 8/10)

Qual é a porcentagem de solicitações que geraram uma resposta lenta?

Para fins deste exemplo, definiremos “lento” como levar mais de 5 segundos para fornecer uma resposta. De acordo:

 # grep "DISPATCH TIME" info.log | grep -cE "\s[0-9]{2,}\.|\s[5-9]\." 2

Resposta: 20% (ou seja, 2/10)

Alguém já forneceu parâmetros GET?

 # grep URI info.log | grep \?

Não, o padrão Symfony usa apenas slugs de URL, então isso também nos diz aqui que ninguém tentou hackear o site.

Esses são apenas alguns exemplos relativamente rudimentares das maneiras pelas quais os arquivos de log podem ser aproveitados de forma criativa para gerar informações valiosas de uso e até análises básicas.

Outras coisas para manter em mente

Mantendo as coisas seguras

Outro alerta é para a segurança. Você pode pensar que registrar solicitações é uma boa ideia, na maioria dos casos, de fato é. No entanto, é importante ser extremamente cuidadoso ao remover quaisquer informações de usuário potencialmente confidenciais antes de armazená-las no log.

Combate ao inchaço do arquivo de log

Como os arquivos de log são arquivos de texto aos quais você sempre anexa informações, eles estão em constante crescimento. Como esse é um problema bem conhecido, existem algumas abordagens bastante padrão para controlar o crescimento do arquivo de log.

O mais fácil é girar os logs . Registros rotativos significam:

• Substituindo periodicamente o log por um novo arquivo vazio para escrita adicional
• Armazenando o arquivo antigo para o histórico
• Removendo arquivos que "envelheceram" o suficiente para liberar espaço em disco
• Certificando-se de que o aplicativo pode gravar nos logs sem interrupções quando essas alterações de arquivo ocorrerem

A solução mais comum para isso é logrotate , que vem pré-instalado com a maioria das distribuições *nix. Vamos ver um arquivo de configuração simples para girar nossos logs:

 /var/log/my/debug.log /var/log/my/info.log /var/log/my/warning.log /var/log/my/error.log { rotate 7 daily missingok notifempty delaycompress compress sharedscripts postrotate invoke-rc.d rsyslog rotate > /dev/null endscript }

Outra abordagem mais avançada é fazer com que o próprio rsyslogd mensagens em arquivos, criados dinamicamente com base na data e hora atuais. Isso ainda exigiria uma solução personalizada para remoção de arquivos mais antigos, mas permite que os devops gerenciem os prazos para cada arquivo de log com precisão. Para o nosso exemplo:

 $template DynaLocal0Err, "/var/log/my/error-%$NOW%-%$HOUR%.log" $template DynaLocal0Info, "/var/log/my/info-%$NOW%-%$HOUR%.log" $template DynaLocal0Warning, "/var/log/my/warning-%$NOW%-%$HOUR%.log" $template DynaLocal0Debug, "/var/log/my/debug-%$NOW%-%$HOUR%.log" local1.err -?DynaLocal0Err local1.info -?DynaLocal0Info local1.warning -?DynaLocal0Warning local1.debug -?DynaLocal0Debug

Dessa forma, o rsyslog criará um arquivo de log individual a cada hora e não haverá necessidade de girá-los e reiniciar o daemon. Veja como os arquivos de log com mais de 5 dias podem ser removidos para realizar esta solução:

 find /var/log/my/ -mtime +5 -print0 | xargs -0 rm

Registros remotos

À medida que o projeto cresce, a análise das informações dos logs torna-se cada vez mais faminta por recursos. Isso não significa apenas criar uma carga extra no servidor; também significa criar picos de carga na CPU e nas unidades de disco nos momentos em que você analisa os logs, o que pode diminuir o tempo de resposta do servidor para os usuários (ou, na pior das hipóteses, pode até derrubar o site).

Para resolver isso, considere configurar um servidor de registro centralizado . Tudo o que você precisa para isso é outra caixa com a porta UDP 514 (padrão) aberta. Para fazer com que o rsyslogd escute as conexões, adicione a seguinte linha ao seu arquivo de configuração:

 $UDPServerRun 514

Tendo isso, configurar o cliente é tão fácil quanto:

 *.* @HOSTNAME:514

(onde HOSTNAME é o nome do host do seu servidor de log remoto).

Conclusão

Embora este artigo tenha demonstrado algumas das maneiras criativas pelas quais os arquivos de log podem oferecer informações muito mais valiosas do que você pode ter imaginado anteriormente, é importante enfatizar que apenas arranhamos a superfície do que é possível. A extensão, o escopo e o formato do que você pode registrar são quase ilimitados. Isso significa que – se houver dados de uso ou análise que você deseja extrair de seus logs – basta registrá-los de uma maneira que facilite a análise e análise subsequentes. Além disso, essa análise geralmente pode ser realizada com ferramentas de linha de comando padrão do Linux, como grep , sed ou awk .

De fato, os arquivos de log do PHP são a ferramenta mais poderosa que pode ser de grande benefício.

Recursos

Código no GitHub: https://github.com/isanosyan/toptal-blog-logs-post-example

Apêndice: Lendo e Manipulando Arquivos de Log no Shell Unix

Aqui está uma breve introdução a algumas das ferramentas de linha de comando *nix mais comuns com as quais você deve se familiarizar para ler e manipular seus arquivos de log.

• cat é talvez o mais simples. Ele imprime o arquivo inteiro no fluxo de saída. Por exemplo, o comando a seguir imprimirá logfile1 no console:

   cat logfile1

• > permite que o usuário redirecione a saída, por exemplo, para outro arquivo. Abre o fluxo de destino no modo de gravação (o que significa limpar o conteúdo de destino). Veja como substituímos o conteúdo de tmpfile pelo conteúdo de logfile1 :

   cat logfile1 > tmpfile

• >> redireciona a saída e abre o fluxo de destino no modo de acréscimo. O conteúdo atual do arquivo de destino será preservado, novas linhas serão adicionadas à parte inferior. Isso anexará o conteúdo do logfile1 ao tmpfile :

   cat logfile1 >> tmpfile

• grep filtra o arquivo por algum padrão e imprime apenas as linhas correspondentes. O comando abaixo imprimirá apenas as linhas do logfile1 contendo a mensagem do Bingo :

   grep Bingo logfile1

• cut imprime o conteúdo de uma única coluna (por número começando em 1). Por padrão, procura caracteres de tabulação como delimitadores entre as colunas. Por exemplo, se você tiver um arquivo cheio de carimbos de data/hora no formato YYYY-MM-DD HH:MM:SS , isso permitirá que você imprima apenas anos:

   cut -d"-" -f1 logfile1

• head exibe apenas as primeiras linhas de um arquivo

• tail exibe apenas as últimas linhas de um arquivo

• sort classifica as linhas na saída

• uniq filtra linhas duplicadas

• wc conta palavras (ou linhas quando usado com o sinalizador -l )

• | (ou seja, o símbolo “pipe”) fornece saída de um comando como entrada para o próximo. Pipe é muito conveniente para combinar comandos. Por exemplo, veja como podemos encontrar meses de 2014 que ocorrem em um conjunto de carimbos de data/hora:

   grep -E "^2014" logfile1 | cut -d"-" -f2 | sort | uniq

Aqui, primeiro combinamos as linhas com a expressão regular “começa com 2014”, depois cortamos meses. Por fim, usamos a combinação de sort e uniq para imprimir ocorrências apenas uma vez.