Logs: O que comem, onde vivem e como se reproduzem

Logs

@augustohp

Logs

@augustohp

O que comem, onde vivem e como se reproduzem.

–RFC 3164: The BSD syslog protocol

“Since the beginning, life has relied upon the transmission of messages.”

Agenda

• O que não são

• O que comem

• Onde vivem

• Como se reproduzem

O que não são

–Hagrid

“… são seres muito incompreendidos.”

• Enfeite

• “Ferramentas” para liberar espaço em disco

• Para apreciação pública

O que comem

O que comemUma dieta configuravel com ênfase em

compatibilidade

Texto

Inglês: ASCII < ISO < UTF

Arquivos simples

1 registro por linha

Registro sempre formatado

Exemplo (Apache access.log)

220.181.108.101 - - [20/Jun/2012:19:31:01 +0200] "GET / HTTP/1.1" 200 912 "-" "Mozilla/5.0 (compatible;!Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"!123.125.68.79 - - [20/Jun/2012:19:53:24 +0200] "GET / HTTP/1.1" 200 625 "-" "Mozilla/5.0 (compatible;!Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"!178.154.210.252 - - [20/Jun/2012:19:54:10 +0200] "GET /?C=S;O=A HTTP/1.1" 200 663 "-" "Mozilla/5.0!(compatible; YandexBot/3.0; +http://yandex.com/bots)"!74.125.126.102 - - [20/Jun/2012:20:15:28 +0200] "GET / HTTP/1.1" 200 606 "http://www.google.com/url?!sa=t&rct=j&q=error&source=web&cd=1&ved=0CFAQFjAG&url=http%3A%2F%2Fwww.isrolab.com!%2F&ei=GxPiT5PsL4e04AHPtgE&usg=AFQjCNHnmjmdkUV584ORIpOXz7zAPX0UHQ" "Mozilla/4.0 (compatible; MSIE 7.0; Windows!NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.648; .NET CLR 3.5.21022; InfoPath.2; .NET!CLR 3.0.4506.2152; .NET CLR 3.5.30729)"!74.125.126.103 - - [20/Jun/2012:20:15:29 +0200] "GET /icons/blank.gif HTTP/1.1" 200 383 "http://!www.isrolab.com/" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR!2.0.50727; .NET CLR 3.0.04506.648; .NET CLR 3.5.21022; InfoPath.2; .NET CLR 3.0.4506.2152; .NET CLR!3.5.30729)"!74.125.126.93 - - [20/Jun/2012:20:15:29 +0200] "GET /icons/folder.gif HTTP/1.1" 200 460 "http://!www.isrolab.com/" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR!2.0.50727; .NET CLR 3.0.04506.648; .NET CLR 3.5.21022; InfoPath.2; .NET CLR 3.0.4506.2152; .NET CLR!3.5.30729)"!74.125.126.82 - - [20/Jun/2012:20:15:30 +0200] "GET /favicon.ico HTTP/1.1" 404 449 "-" "Mozilla/4.0!(compatible; MSIE 7.0; Windows NT 5.1; .NET CLR 1.1.4322; .NET CLR 2.0.50727; .NET CLR 3.0.04506.648; .NET CLR!3.5.21022; InfoPath.2; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729)"!184.82.92.239 - - [20/Jun/2012:21:03:44 +0200] "GET /logs/access.log HTTP/1.1" 200 2519 "http://isrolab.com/"!"Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.0; Trident/4.0; Mozilla/4.0 (compatible; MSIE 6.0; Windows NT!5.1; SV1) ; .NET CLR 3.5.30729)"!173.236.21.106 - - [20/Jun/2012:21:16:22 +0200] "GET /robots.txt HTTP/1.0" 404 488 "-" "Mozilla/5.0!(compatible; MJ12bot/v1.4.3; http://www.majestic12.co.uk/bot.php?+)"!173.236.21.106 - - [20/Jun/2012:21:16:23 +0200] "GET / HTTP/1.0" 200 621 "-" "Mozilla/5.0 (compatible;!MJ12bot/v1.4.3; http://www.majestic12.co.uk/bot.php?+)"!213.186.122.2 - - [20/Jun/2012:21:27:53 +0200] "GET /logs/?C=D;O=D HTTP/1.1" 200 658 "-" "Mozilla/5.0!(compatible; AhrefsBot/3.0; +http://ahrefs.com/robot/)"!66.249.72.65 - - [20/Jun/2012:21:28:00 +0200] "GET /robots.txt HTTP/1.1" 404 508 "-" "Mozilla/5.0 (compatible;!Googlebot/2.1; +http://www.google.com/bot.html)"!66.249.72.65 - - [20/Jun/2012:21:28:00 +0200] "GET /logs/ HTTP/1.1" 200 723 "-" "Mozilla/5.0 (compatible;!Googlebot/2.1; +http://www.google.com/bot.html)"!123.125.71.44 - - [20/Jun/2012:21:38:57 +0200] "GET / HTTP/1.1" 200 913 "-" "Mozilla/5.0 (compatible;!Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"!220.181.108.88 - - [20/Jun/2012:21:39:48 +0200] "GET / HTTP/1.1" 200 913 "-" "Mozilla/5.0 (compatible;!Baiduspider/2.0; +http://www.baidu.com/search/spider.html)"!178.154.210.252 - - [20/Jun/2012:21:45:12 +0200] "GET /logs/ HTTP/1.1" 200 728 "-" "Mozilla/5.0 (compatible;!YandexBot/3.0; +http://yandex.com/bots)"!139.18.2.209 - - [20/Jun/2012:22:31:43 +0200] "GET / HTTP/1.1" 200 912 "-" "findlinks/2.6 (+http://!wortschatz.uni-leipzig.de/findlinks/)"!

http://wortschatz.uni-leipzig.de/findlinks/


1 registro por linha …



1 registro por linha …… ou “quebra de linha”.



Separadas por espaço…



… ou entre “ ” (aspas) …Separadas por espaço…



… ou entre “ ” (aspas) …Separadas por espaço…

… ou [ ] (colchetes).



Informações ausentes como um - (hífem).


Como estudar/usar

wcword, line, character and byte count

#!/bin/bash [~/Apache] $ wc -l access.log 65063 access.log

headdisplay first lines of a file

#!/bin/bash [~/Apache]$ head -n 1 access.log1.202.218.8 - - [20/Jun/2012:19:05:12 +0200] "GET /robots.txt HTTP/1.0" 404 492 "-" "\"Mozilla/5.0"

taildisplay the last lines of a file

#!/bin/bash [~/Apache] $ tail -n 1 access.log192.210.213.91 - - [08/Jun/2014:19:42:34 -0700] "GET /logs/access.log HTTP/1.1" 200 4663 "http://redlug.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1" "redlug.com"

http://redlug.com

#!/bin/bash [~/Apache] $ tail -n 1 -f access.log192.210.213.91 - - [08/Jun/2014:19:42:34 -0700] "GET /logs/access.log HTTP/1.1" 200 4663 "http://redlug.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_4) AppleWebKit/536.30.1 (KHTML, like Gecko) Version/6.0.5 Safari/536.30.1" "redlug.com"

http://redlug.com

grepprint lines matching a pattern

#!/bin/bash [~/Apache] $ grep "HTTP/1.1" access.log | wc -l 52129!

#!/bin/bash [~/Apache] $ grep "HTTP/1.1" access.log | wc -l 52129![~/Apache] $ grep "HTTP/1.0" access.log | wc -l 13007!

#!/bin/bash [~/Apache] $ grep "HTTP/1.1" access.log | wc -l 52129![~/Apache] $ grep "HTTP/1.0" access.log | wc -l 13007![~/Apache] $ grep -v "HTTP/1.1" access.log | \ grep -v “HTTP/1.0"114.66.65.89 - - [24/Dec/2012:07:46:27 +0100] "GET /logs/access.log v\xc2\xa4N\xd41.0" 200 1963700 "http://www.isrolab.com/" "Mozilla/5.0 (Windows NT 6.1; rv:2.0b7pre)Gecko/20100921 Firefox/4.0b7pre"!

#!/bin/bash [~/Apache] $ grep "HTTP/1.1" access.log | wc -l 52129![~/Apache] $ grep "HTTP/1.0" access.log | wc -l 13007![~/Apache] $ grep -v "HTTP/1.1" access.log | \ grep -v “HTTP/1.0"114.66.65.89 - - [24/Dec/2012:07:46:27 +0100] "GET /logs/access.log v\xc2\xa4N\xd41.0" 200 1963700 "http://www.isrolab.com/" "Mozilla/5.0 (Windows NT 6.1; rv:2.0b7pre)Gecko/20100921 Firefox/4.0b7pre"!

awkpattern-directed scanning and processing language

#!/bin/bash [~/Apache]$ head -n 1 access.log1.202.218.8 - - [20/Jun/2012:19:05:12 +0200] "GET /robots.txt HTTP/1.0" 404 492 "-" “\"Mozilla/5.0"!

#!/bin/bash [~/Apache]$ head -n 1 access.log1.202.218.8 - - [20/Jun/2012:19:05:12 +0200] "GET /robots.txt HTTP/1.0" 404 492 "-" “\"Mozilla/5.0"![~/Apache]$ head -n 1 access.log | awk '{print $1}'1.202.218.8

#!/bin/bash [~/Apache]$ head -n 1 access.log1.202.218.8 - - [20/Jun/2012:19:05:12 +0200] "GET /robots.txt HTTP/1.0" 404 492 "-" “\"Mozilla/5.0"![~/Apache]$ head -n 1 access.log | awk '{print $1}'1.202.218.8![~/Apache] $ awk '/access.log/' access.log | awk '{print $1}'31.184.238.16431.184.238.16477.27.18.6731.184.238.16431.184.238.16431.184.238.16431.184.238.16431.184.238.164

#!/bin/bash [~/Apache] $ awk '/access.log/' access.log | awk '{print $1,$6,$7,$8}'31.184.238.164 "GET /logs/access.log HTTP/1.0"31.184.238.164 "GET /logs/access.log HTTP/1.0"77.27.18.67 "GET /logs/access.log HTTP/1.1"31.184.238.164 "GET /logs/access.log HTTP/1.0"31.184.238.164 "GET /logs/access.log HTTP/1.0"31.184.238.164 "GET /logs/access.log HTTP/1.0"

uniq / sort

#!/bin/bash [~/Apache] $ awk '/access.log/' access.log | \ awk '{print $1}' | \ sort | \ uniq -c | \ sort -r

#!/bin/bash [~/Apache] $ awk '/access.log/' access.log | \ awk '{print $1}' | \ sort | \ uniq -c | \ sort -r! 41 31.184.238.164 2 192.210.213.91 1 77.27.18.67 1 192.227.243.66 1 189.120.185.4

Onde vivem

/var/logSeu administrador de sistemas agradece.

Seres famosos (Debian)

• /var/log/apache2/access.log

• /var/log/apache2/error.log

• /var/log/messages

• /var/log/mysql.err

Como se reproduzem

PHPE seus métodos anticoncepcionais

display_errorsOs erros devem ser exibidos para o usuário?

ini_set(‘display_errors’, ‘On’)Exibe os erros ao usuário.

O PHP respeita o cabeçalho HTTP “Content-Type”.

ini_set(‘display_errors’, 1)Também é interpretado como “On”.

ini_set(‘display_errors’, true)Também é interpretado como “On”.

$isDev = true; ini_set(‘display_errors’, $isDev)

Também é interpretado como “On”.

$isDev =“1 caralhinho”; ini_set(‘display_errors’, $isDev)

Isso também é “On”.

$isDev =“2 caralhinhos”; ini_set(‘display_errors’, $isDev)

Isso é “Off”.

log_errorsOs erros devem ser mantidos?

log_errorsOs erros devem ser mantidos?

Siiiiiiiiiiiim!

ini_set(‘log_errors’, ‘1 caralhinho’)Garante que os logs sejam salvos.

error_logOnde manter o arquivo de log?

ini_set(‘error_log’, ‘/tmp/app.log’)Salva os logs em “/tmp/app.log” (não é uma boa idéia)

ini_set(‘error_log’, ‘syslog’)Envia erros para o syslog (Unix), ou “Event

log” (Windows).

ini_set(‘error_log’, ‘’)Padrão: Error log do SAPI (Apache/NGINX) ou STDERR

em CLI.

error_reportingQuais severidades devem ser mantidas (php.ini)

SeveridadesE pra quê servem.

Severidade Exibida (default) Pára execução

E_ERROR Sim Sim

E_WARNING Sim Não

E_NOTICE Não Não

E_STRICT Não Não

E_DEPRECATED Não Não

PHP >=5.3

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 if ($_POST['user']) { 6 // ... 7 }

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 if ($_POST['user']) { 6 // ... 7 } 8 /**

9 * Output:10 *11 * PHP Notice: Undefined index: user in notices.php on line 512 */

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL & ~E_NOTICE); 4 5 if ($_POST['user']) { 6 // ... 7 } 8 /**

9 * Output:10 *11 *12 */

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL ^E_NOTICE); 4 5 if ($_POST['user']) { 6 // ... 7 } 8 /**

9 * Output:10 *11 *12 */

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 echo date('l').PHP_EOL; 6 7 date_default_timezone_set('America/Sao_Paulo'); 8 9 echo date('l').PHP_EOL;

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 echo date('l').PHP_EOL; 6 7 date_default_timezone_set('America/Sao_Paulo'); 8 9 echo date('l').PHP_EOL;1011 /**12 * Output:13 *14 * PHP Warning: date(): It is not safe to rely on the system's15 * timezone settings. You are *required* to use the date.timezone16 * setting or the date_default_timezone_set() function.17 * In case you used any of those methods and you are still getting18 * this warning, you most likely misspelled the timezone identifier.19 * We selected the timezone 'UTC' for now, but please set date.timezone20 * to select your timezone. in date.php on line 521 *22 * Saturday23 * Saturday24 */

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 include 'nao-existe.php';

1 <?php 2 ini_set('display_errors', 1); 3 error_reporting(E_ALL); 4 5 include 'nao-existe.php'; 6 7 /** 8 * Output: 9 * 10 * PHP Warning: include(nao-existe.php): failed to open stream:

11 * No such file or directory in warning.php on line 512 */

DesenvolvedorGerando informações para logs.

error_log()Gerando logs

1 <?php 2 3 ini_set('display_errors', 1); 4 ini_set('error_log', __DIR__.'/example.log'); 5 error_reporting(-1); 6 date_default_timezone_set('America/Sao_Paulo'); 7 8 error_log('Some log message.'); 9 error_log('This goes to /tmp.', 3, '/tmp/app.log');

#!/bin/bash[~/PHP] $ php error_log.php

#!/bin/bash[~/PHP] $ php error_log.php!

[~/PHP] $ lserror_log.php example.log

#!/bin/bash[~/PHP] $ php error_log.php!

[~/PHP] $ lserror_log.php example.log!

[~/PHP] $ tail example.log[10-Jun-2014 00:23:09 America/Sao_Paulo] Some log message

trigger_error()Gera um erro no espaço de usuário

1 <?php 2 3 ini_set('display_errors', 1); 4 ini_set('error_log', __DIR__.'/example.log'); 5 error_reporting(-1); 6 date_default_timezone_set('America/Sao_Paulo'); 7 8 trigger_error('Start using this!', E_USER_NOTICE);

#!/bin/bash[~/apascutti] $ php trigger_error.phpNotice: Start using this! in /Users/apascutti/Desktop/erros/source/trigger_error.php on line 8Call Stack: 0.0001 228560 1. {main}() /Users/apascutti/trigger_error.php:0 0.0002 229328 2. trigger_error() /Users/apascutti/trigger_error.php:8

ExceptionErros orientados a objetos, ou a “capivara” da merda.

1 <?php 2 3 ini_set('display_errors', 1); 4 ini_set('error_log', __DIR__.'/example.log'); 5 error_reporting(-1); 6 date_default_timezone_set('America/Sao_Paulo'); 7 8 throw new Exception('Shit happens...');

#!/bin/bash[~/Desktop/erros/source] $ php exception.php!Fatal error: Uncaught exception 'Exception' with message 'Shit happens...' in /Users/apascutti/Desktop/erros/source/exception.php on line 8!Exception: Shit happens... in /Users/apascutti/Desktop/erros/source/exception.php on line 8!Call Stack: 0.0002 228584 1. {main}() /Users/apascutti/Desktop/erros/source/exception.php:0

#!/bin/bash[~/Desktop/erros/source] $ php exception.php!Fatal error: Uncaught exception 'Exception' with message 'Shit happens...' in /Users/apascutti/Desktop/erros/source/exception.php on line 8!Exception: Shit happens... in /Users/apascutti/Desktop/erros/source/exception.php on line 8!Call Stack: 0.0002 228584 1. {main}() /Users/apascutti/Desktop/erros/source/exception.php:0![~/Desktop/erros/source] $ tail example.log[10-Jun-2014 00:35:19 America/Sao_Paulo] PHP Fatal error: Uncaught exception 'Exception' with message 'Shit happens...' in /Users/apascutti/exception.php:8Stack trace:#0 {main} thrown in /Users/apascutti/exception.php on line 8

1 <?php 2 3 ini_set('display_errors', 1); 4 ini_set('error_log', __DIR__.'/example.log'); 5 error_reporting(-1); 6 date_default_timezone_set('America/Sao_Paulo'); 7 8 try { 9 throw new Exception('Shit happens...'); 10 } catch (Exception $e) { 11 throw new Exception('and hit the fan.', 14, $e); 12 }

#!/bin/bash[~/apascutti] $ php exception.php!Fatal error: Uncaught exception 'Exception' with message 'Shit happens...' in /Users/apascutti/exception.php on line 11!Exception: Shit happens... in /Users/apascutti/exception.php on line 9!Call Stack: 0.0002 229536 1. {main}() /Users/apascutti/exception.php:0!Exception: and hit the fan. in /Users/apascutti/exception.php on line 11!Call Stack: 0.0002 229536 1. {main}() /Users/apascutti/exception.php:0

PSR-3Interface Orientada a Objetos para implementação de

Loggers.

1 <?php 2 3 namespace Psr\Log; 4 5 abstract class AbstractLogger implements LoggerInterface 6 { 7 public function emergency($message, array $context=array()) 11 12 public function alert($message, array $context = array()) 16 17 public function critical($message, array $context = array()) 21 22 public function error($message, array $context = array()) 26 27 public function warning($message, array $context = array()) 31 32 public function notice($message, array $context = array()) 36 37 public function info($message, array $context = array()) 41 42 public function debug($message, array $context = array()) 43 { 44 $this->log(LogLevel::DEBUG, $message, $context); 45 } 46 }

1 <?php 2 3 namespace MyApp\Integration\Command; 4 5 use MyApp\Console; 6 use Psr\Log\LoggerInterface; 7 8 class DoShit implements Console\CommandInterface 9 { 10 const NAME = 'hankey'; 11 private $logger; 12 13 public function __construct(LoggerInterface $logger) 14 { 15 $this->logger = $logger; 16 } 17 18 public function configure(Console\Command\Definition $builder) 24 25 public function execute(Console\Input $in, Console\Output $out) 26 { 27 $logContext = array('command'=>self::NAME); 28 29 $this->logger->debug('Start', $logContext); 30 $this->logger->warning('This is a joke', $logContext); 31 $this->logger->debug('End', $logContext); 32 } 33 }

Uma boa mensagemOu como tornar as mensagens de log da sua aplicação

mais úteis.

• Em inglês.

• “grep”ável.

• Objetiva, sem pleonamos nem contexto.

• Descreve uma expectativa.

AdministradorComo isso tudo parece no fim das contas.

2014/01/10 23:28:24 [/shop/test/TestSuite.php] Warning(E_WARNING): include(PHPUnit/Framework/TestCase.php) [<a href='function.include'>function.include</a>]: failed to open stream: No such file or directory on [/home/nihon-store/www/nihon-store/shop/data/class/SC_ClassAutoloader.php(120)] from 66.249.74.101

2014/01/10 23:28:24 [/shop/test/TestSuite.php] Warning(E_WARNING): include() [<a href='function.include'>function.include</a>]: Failed opening 'PHPUnit/Framework/TestCase.php' for inclusion (include_path='/home/nihon-store/www/nihon-store/shop/data/module:.:/usr/local/php/5.2.17/lib/php:/opt/local/lib/php') on [/home/nihon-store/www/nihon-store/shop/data/class/SC_ClassAutoloader.php(120)] from 66.249.74.101

2014/01/10 23:28:24 [/shop/test/TestSuite.php] Fatal error(E_ERROR): Class 'PHPUnit_Framework_TestCase' not found on [/home/nihon-store/www/nihon-store/shop/test/class/page/LC_Page_Test.php(35)] from 66.249.74.101 customer_id =

2014/01/10 23:41:41 [/shop/test/createEcCubeData-v25.php] Warning(E_WARNING): getopt() [<a href='function.getopt'>function.getopt</a>]: No support for long options in this build on [/home/nihon-store/www/nihon-store/shop/test/createEcCubeData-v25.php(119)] from 66.249.74.101



























Data











Arquivo











Severidade











Mensagem

Dúvidas?Ou sugestões, reclamações? Críticas? Elogios?

Cerveja?!

Software

Logs: O que comem, onde vivem e como se reproduzem