Ottenere il massimo dai file di registro PHP: una guida pratica

Si potrebbe giustamente affermare che i log sono uno degli strumenti più sottovalutati e sottoutilizzati a disposizione di uno sviluppatore php freelance. Nonostante la ricchezza di informazioni che possono offrire, non è raro che i registri siano l' ultimo posto in cui uno sviluppatore cerca quando cerca di risolvere un problema.

In verità, i file di registro PHP dovrebbero in molti casi essere il primo posto in cui cercare indizi quando si verificano problemi. Spesso, le informazioni che contengono potrebbero ridurre significativamente la quantità di tempo trascorso a strapparsi i capelli cercando di rintracciare un insetto nodoso.

Ma forse ancora più importante, con un po' di creatività e accortezza, i file di registro possono essere sfruttati per fungere da preziosa fonte di informazioni sull'utilizzo e analisi. L'uso creativo dei file di registro può aiutare a rispondere a domande quali: Quali browser vengono utilizzati più comunemente per visitare il mio sito? Qual è il tempo medio di risposta dal mio server? Qual è stata la percentuale di richieste alla radice del sito? Come è cambiato l'utilizzo da quando abbiamo distribuito gli ultimi aggiornamenti? E molto, molto di più.

Questo articolo fornisce una serie di suggerimenti su come configurare i file di registro e su come elaborare le informazioni in essi contenute per massimizzare i vantaggi che offrono.

Sebbene questo articolo si concentri tecnicamente sulla registrazione per gli sviluppatori PHP, molte delle informazioni qui presentate sono abbastanza indipendenti dalla tecnologia e sono rilevanti anche per altri linguaggi e stack tecnologici.

Nota: questo articolo presuppone una familiarità di base con la shell Unix. Per coloro che non hanno questa conoscenza, viene fornita un'Appendice che introduce alcuni dei comandi necessari per accedere e leggere i file di registro su un sistema Unix.

Il nostro progetto di esempio di file di registro PHP

Come progetto di esempio per scopi di discussione in questo articolo, prenderemo Symfony Standard come progetto funzionante e lo configureremo su Debian 7 Wheezy con rsyslogd , nginx e PHP-FPM .

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

Questo ci dà rapidamente un progetto di test funzionante con una bella interfaccia utente.

Suggerimenti per la configurazione dei file di registro

Di seguito sono riportati alcuni suggerimenti su come configurare i file di registro per massimizzarne il valore.

Configurazione registro errori

I registri degli errori rappresentano la forma più semplice di registrazione; cioè, acquisire informazioni e dettagli aggiuntivi quando si verificano problemi. Quindi, in un mondo ideale, vorresti che non ci fossero errori e che i tuoi registri degli errori fossero vuoti. Ma quando si verificano problemi (come accade invariabilmente), i registri degli errori dovrebbero essere una delle prime fermate che si effettuano durante il percorso di debug.

I registri degli errori sono in genere abbastanza facili da configurare.

Per prima cosa, tutti i messaggi di errore e di arresto anomalo possono essere registrati nel registro degli errori esattamente nello stesso formato in cui verrebbero altrimenti presentati a un utente. Con una semplice configurazione, l'utente finale non avrà mai bisogno di vedere quelle brutte tracce di errore sul tuo sito, mentre i devops saranno comunque in grado di monitorare il sistema e rivedere questi messaggi di errore in tutti i loro dettagli cruenti. Ecco come impostare questo tipo di accesso in PHP:

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

Altre due righe che è importante includere in un file di registro per un sito live, per impedire che livelli cruenti di dettagli di errore vengano presentati agli utenti, sono:

 display_errors = Off display_startup_errors = Off

Configurazione del registro di sistema ( syslog ).

Esistono molte implementazioni generalmente compatibili del demone syslog nel mondo open source, tra cui:

• syslogd e sysklogd : visti più spesso sui sistemi della famiglia BSD, CentOS, Mac OS X e altri
• syslog-ng – predefinito per le build moderne di Gentoo e SuSE
• rsyslogd – ampiamente utilizzato sulle famiglie di sistemi operativi Debian e Fedora

(Nota: in questo articolo, useremo rsyslogd per i nostri esempi.)

La configurazione di base di syslog è generalmente adeguata per acquisire i messaggi di registro in un file di registro a livello di sistema (normalmente /var/log/syslog ; potrebbe anche essere /var/log/messages o /var/log/system.log a seconda della distribuzione stai usando).

Il registro di sistema fornisce diverse funzionalità di registro, otto delle quali ( da LOG_LOCAL0 a LOG_LOCAL7 ) sono riservate ai progetti distribuiti dall'utente. Ecco, ad esempio, come impostare LOG_LOCAL0 per scrivere in 4 file di registro separati, in base al livello di registrazione (ad es. errore, avviso, informazioni, debug):

 # /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

Ora, ogni volta che scrivi un messaggio di registro nella struttura LOG_LOCAL0 , i messaggi di errore andranno a /var/log/my/err.log , i messaggi di avviso andranno a /var/log/my/warning.log e così via. Si noti, tuttavia, che il demone syslog filtra i messaggi per ogni file in base alla regola di "questo livello e superiore". Quindi, nell'esempio sopra, tutti i messaggi di errore appariranno in tutti e quattro i file configurati, i messaggi di avviso appariranno in tutti tranne il registro degli errori, i messaggi informativi appariranno nelle informazioni e nei registri di debug e i messaggi di debug andranno solo a debug.log .

Una nota importante aggiuntiva; I segni - prima dei file di livello di informazioni e debug nell'esempio di file di configurazione sopra indicano che le scritture su tali file devono essere eseguite in modo asincrono (poiché queste operazioni non sono bloccanti). Questo in genere va bene (e anche consigliato nella maggior parte delle situazioni) per informazioni e registri di debug, ma è meglio che le scritture nel registro degli errori (e molto probabilmente anche nel registro degli avvisi) siano sincrone.

Per chiudere un livello di registrazione meno importante (ad esempio, su un server di produzione), puoi semplicemente reindirizzare i messaggi correlati a /dev/null (ad esempio, da nessuna parte):

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

Una personalizzazione specifica utile, soprattutto per supportare parte dell'analisi del file di registro PHP di cui parleremo più avanti in questo articolo, consiste nell'usare tab come carattere delimitatore nei messaggi di registro. Questo può essere fatto facilmente aggiungendo il seguente file in /etc/rsyslog.d :

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

E infine, non dimenticare di riavviare il demone syslog dopo aver apportato modifiche alla configurazione affinché abbiano effetto:

 service rsyslog restart

Configurazione del registro del server

A differenza dei registri delle applicazioni e dei registri degli errori su cui è possibile scrivere, i registri del server vengono scritti esclusivamente dai demoni del server corrispondenti (ad esempio, server Web, server di database, ecc.) su ogni richiesta. L'unico "controllo" che hai su questi registri è nella misura in cui il server ti consente di configurare la sua funzionalità di registrazione. Sebbene ci possa essere molto da vagliare in questi file, spesso sono l'unico modo per avere un'idea chiara di cosa sta succedendo "sotto il cofano" con il tuo server.

Distribuiamo la nostra applicazione di esempio Symfony Standard sull'ambiente nginx con il backend di archiviazione MySQL. Ecco la configurazione dell'host nginx che useremo:

 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; }

Per quanto riguarda le ultime due direttive precedenti: access_log rappresenta il registro generale delle richieste, mentre error_log è per gli errori e, come per i registri degli errori dell'applicazione, vale la pena impostare un monitoraggio aggiuntivo per essere avvisati dei problemi in modo da poter reagire rapidamente.

Nota: questo è un file di configurazione nginx intenzionalmente semplificato che viene fornito solo a scopo di esempio. Non presta quasi alcuna attenzione alla sicurezza e alle prestazioni e non dovrebbe essere utilizzato così com'è in nessun ambiente "reale".

Questo è ciò che otteniamo in /var/log/nginx/my_access.log dopo aver digitato http://my.log-sandbox/app_dev.php/ nel browser e aver premuto 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"

Questo mostra che, per servire una pagina, il browser esegue effettivamente 9 chiamate HTTP. 7 di queste, invece, sono richieste a contenuto statico, che sono semplici e leggere. Tuttavia, prendono ancora risorse di rete e questo è ciò che può essere ottimizzato utilizzando vari sprite e tecniche di minimizzazione.

Mentre queste ottimizzazioni devono essere discusse in un altro articolo, ciò che è rilevante qui è che possiamo registrare le richieste su contenuti statici separatamente usando un'altra direttiva di location per loro:

 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; }

Ricorda che la location di nginx esegue una semplice corrispondenza di espressioni regolari, quindi puoi includere tutte le estensioni di contenuti statici che prevedi di inviare sul tuo sito.

L'analisi di tali registri non è diversa dall'analisi dei registri dell'applicazione.

Altri registri degni di nota

Altri due registri PHP degni di nota sono il registro di debug e il registro di archiviazione dei dati.

Il registro di debug

Un'altra cosa utile dei log di nginx è il log di debug. Possiamo attivarlo sostituendo la riga error_log della configurazione con la seguente (richiede l'installazione del modulo di debug nginx):

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

La stessa impostazione si applica ad Apache o qualsiasi altro server web che utilizzi.

E per inciso, i log di debug non sono correlati ai log di errore, anche se sono configurati nella direttiva error_log .

Sebbene il registro di debug possa effettivamente essere dettagliato (una singola richiesta nginx, ad esempio, ha generato 127 KB di dati di registro!), può comunque essere molto utile. L'esplorazione di un file di registro può essere ingombrante e noioso, ma spesso può fornire rapidamente indizi e informazioni che aiutano notevolmente ad accelerare il processo di debug.

In particolare, il registro di debug può davvero aiutare con il debug delle configurazioni di nginx, in particolare le parti più complicate, come la corrispondenza location e le catene di rewrite .

Naturalmente, i log di debug non dovrebbero mai essere abilitati in un ambiente di produzione. La quantità di spazio che utilizzano e la quantità di informazioni che memorizzano significano molto carico di I/O sul server, che può degradare significativamente le prestazioni dell'intero sistema.

Registri di archiviazione dati

Un altro tipo di registro del server (utile per il debug) sono i registri di archiviazione dati. In MySQL, puoi attivarli aggiungendo queste righe:

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

Questi registri contengono semplicemente un elenco di query eseguite dal sistema mentre servono le richieste del database in ordine cronologico, che può essere utile per varie esigenze di debug e traccia. Tuttavia, non dovrebbero rimanere abilitati sui sistemi di produzione, poiché genereranno un carico I/O aggiuntivo non necessario, che influirà sulle prestazioni.

Scrivere nei tuoi file di registro

Lo stesso PHP fornisce funzioni per l'apertura, la scrittura e la chiusura di file di registro ( openlog() , syslog() e closelog() , rispettivamente).

Ci sono anche numerose librerie di logging per lo sviluppatore PHP, come Monolog (popolare tra gli utenti di Symfony e Laravel), così come varie implementazioni specifiche del framework, come le capacità di logging incorporate in CakePHP. In genere, librerie come Monolog non solo avvolgono le chiamate syslog() , ma consentono anche di utilizzare altre funzionalità e strumenti di back-end.

Ecco un semplice esempio di come scrivere nel log:

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

La nostra chiamata qui per openlog :

• configura PHP per anteporre un identificatore univoco a ogni messaggio di registro di sistema durante la vita dello script
• lo imposta per ritardare l'apertura della connessione syslog fino a quando non si è verificata la prima chiamata syslog()
• imposta LOG_LOCAL0 come funzione di registrazione predefinita

Ecco come sarebbe il contenuto del file di registro dopo aver eseguito il codice sopra:

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

Massimizzazione del valore dei file di registro PHP

Ora che siamo tutti bravi con la teoria e le basi, vediamo quanto possiamo ottenere dai log apportando il minor numero di modifiche possibile al nostro progetto Symfony Standard di esempio.

Per prima cosa, creiamo gli script src/log-begin.php (per aprire e configurare correttamente i nostri log) e src/log-end.php (per registrare le informazioni sul completamento con successo). Nota che, per semplicità, scriveremo semplicemente tutti i messaggi nel registro delle informazioni.

 # 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 richiediamo questi script in 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');

Per l'ambiente di sviluppo, vogliamo anche richiedere questi script in app_dev.php . Il codice per farlo sarebbe lo stesso di sopra, tranne per il fatto che avremmo impostato MODE su DEV anziché PROD .

Vogliamo anche tenere traccia di quali controller vengono invocati, quindi aggiungiamo un'altra riga in Acme\DemoBundle\EventListener\ControllerListener , proprio all'inizio del metodo ControllerListener::onKernelController() :

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

Si noti che queste modifiche totalizzano solo 15 righe di codice in più, ma possono produrre collettivamente una grande quantità di informazioni.

Analisi dei dati nei file di registro

Per cominciare, vediamo quante richieste HTTP sono necessarie per servire ogni caricamento di pagina.

Ecco le informazioni nei registri per una richiesta, in base al modo in cui abbiamo configurato la nostra registrazione:

 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

Quindi ora sappiamo che ogni caricamento di pagina viene effettivamente servito con due richieste HTTP.

In realtà ci sono due punti degni di nota qui. Innanzitutto, le due richieste per caricamento della pagina servono per usare Symfony in modalità dev (cosa che ho fatto in questo articolo). Puoi identificare le chiamate in modalità dev cercando i blocchi URL /app-dev.php/ . Secondo, diciamo che ogni caricamento di pagina viene servito con due richieste successive all'app Symfony. Come abbiamo visto in precedenza nei log di accesso di nginx, in realtà ci sono più chiamate HTTP, alcune delle quali sono per contenuto statico.

OK, ora navighiamo un po' sul sito demo (per costruire i dati nei file di registro) e vediamo cos'altro possiamo imparare da questi registri.

Quante richieste sono state soddisfatte in totale dall'inizio del file di registro?

 # grep -c BEGIN info.log 10

Qualcuno di loro ha fallito (lo script si è chiuso senza raggiungere la fine)?

 # grep -c END info.log 10

Vediamo che il numero di record BEGIN e END corrisponde, quindi questo ci dice che tutte le chiamate hanno avuto successo. (Se lo script PHP non fosse stato completato correttamente, non avrebbe raggiunto l'esecuzione dello script src/log-end.php .)

Qual è stata la percentuale di richieste alla radice del sito?

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

Questo ci dice che c'erano 2 caricamenti di pagina della radice del sito. Poiché in precedenza abbiamo appreso che (a) ci sono 2 richieste all'app per caricamento della pagina e (b) c'erano un totale di 10 richieste HTTP, la percentuale di richieste alla radice del sito era del 40% (cioè, 2x2/10).

Quale classe di controller è responsabile della gestione delle richieste al root del sito?

 # 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

Qui abbiamo utilizzato l'ID univoco di una richiesta per controllare tutti i messaggi di registro relativi a quella singola richiesta. In tal modo siamo stati in grado di determinare che la classe controller responsabile della gestione delle richieste alla radice del sito è Acme\DemoBundle\Controller\WelcomeController .

Quali client con IP della sottorete 192.168.0.0/16 hanno avuto accesso al sito?

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

Come previsto in questo semplice test case, solo il mio computer host ha avuto accesso al sito. Questo è ovviamente un esempio molto semplicistico, ma la capacità che dimostra (di essere in grado di analizzare le fonti del traffico verso il tuo sito) è ovviamente abbastanza potente e importante.

Quanto del traffico al mio sito è stato da FireFox?

Avendo 1b101cd come hash del mio User-Agent di Firefox, posso rispondere a questa domanda come segue:

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

Risposta: 80% (cioè 8/10)

Qual è la percentuale di richieste che hanno prodotto una risposta lenta?

Ai fini di questo esempio, definiremo "lento" come impiega più di 5 secondi per fornire una risposta. Di conseguenza:

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

Risposta: 20% (cioè 2/10)

Qualcuno ha mai fornito parametri GET?

 # grep URI info.log | grep \?

No, lo standard Symfony utilizza solo slug URL, quindi questo ci dice anche qui che nessuno ha tentato di hackerare il sito.

Questi sono solo una manciata di esempi relativamente rudimentali dei modi in cui i file di registro possono essere sfruttati in modo creativo per produrre preziose informazioni sull'utilizzo e persino analisi di base.

Altre cose da tenere a mente

Mantenere le cose al sicuro

Un altro avviso è per la sicurezza. Potresti pensare che la registrazione delle richieste sia una buona idea, nella maggior parte dei casi lo è davvero. Tuttavia, è importante prestare la massima attenzione alla rimozione di qualsiasi informazione utente potenzialmente sensibile prima di archiviarla nel registro.

File di registro di combattimento gonfio

Poiché i file di registro sono file di testo a cui si aggiungono sempre informazioni, sono in costante crescita. Poiché si tratta di un problema ben noto, esistono alcuni approcci abbastanza standard per controllare la crescita dei file di registro.

Il più semplice è ruotare i registri . Tronchi rotanti significa:

• Sostituendo periodicamente il registro con un nuovo file vuoto per ulteriori scritture
• Memorizzazione del vecchio file per la cronologia
• Rimozione di file che sono "invecchiati" sufficientemente per liberare spazio su disco
• Assicurarsi che l'applicazione possa scrivere nei registri interrotti quando si verificano queste modifiche ai file

La soluzione più comune per questo è logrotate , che viene fornito preinstallato con la maggior parte delle distribuzioni *nix. Vediamo un semplice file di configurazione per la rotazione dei nostri log:

 /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 }

Un altro approccio più avanzato consiste nel fare in modo che rsyslogd stesso scriva messaggi in file, creati dinamicamente in base alla data e all'ora correnti. Ciò richiederebbe comunque una soluzione personalizzata per la rimozione dei file meno recenti, ma consente ai devops di gestire con precisione i tempi per ciascun file di registro. Per il nostro esempio:

 $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

In questo modo, rsyslog creerà un file di registro individuale ogni ora e non sarà necessario ruotarli e riavviare il demone. Ecco come è possibile rimuovere i file di registro più vecchi di 5 giorni per ottenere questa soluzione:

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

Registri remoti

Man mano che il progetto cresce, l'analisi delle informazioni dai log diventa sempre più affamata di risorse. Questo non significa solo creare un carico aggiuntivo sul server; significa anche creare un carico di picco sulla CPU e sulle unità disco nei momenti in cui si analizzano i registri, il che può ridurre i tempi di risposta del server per gli utenti (o, nel peggiore dei casi, persino portare il sito inattivo).

Per risolvere questo problema, considera la configurazione di un server di registrazione centralizzato . Tutto ciò che serve per questo è un'altra scatola con la porta UDP 514 (predefinita) aperta. Per fare in modo che rsyslogd ascolti le connessioni, aggiungi la seguente riga al suo file di configurazione:

 $UDPServerRun 514

Avendo questo, configurare il client è facile come:

 *.* @HOSTNAME:514

(dove HOSTNAME è il nome host del server di registrazione remoto).

Conclusione

Sebbene questo articolo abbia dimostrato alcuni dei modi creativi in ​​cui i file di registro possono offrire informazioni molto più preziose di quelle che potresti aver immaginato in precedenza, è importante sottolineare che abbiamo solo scalfito la superficie di ciò che è possibile. L'estensione, l'ambito e il formato di ciò che puoi registrare è quasi illimitato. Ciò significa che, se ci sono dati di utilizzo o di analisi che desideri estrarre dai tuoi log, devi semplicemente registrarli in un modo che semplificherà successivamente l'analisi e l'analisi. Inoltre, tale analisi può essere spesso eseguita con strumenti a riga di comando Linux standard come grep , sed o awk .

In effetti, i file di registro PHP sono uno strumento molto potente che può essere di enorme vantaggio.

Risorse

Codice su GitHub: https://github.com/isanosyan/toptal-blog-logs-post-example

Appendice: lettura e manipolazione dei file di registro nella shell Unix

Ecco una breve introduzione ad alcuni dei più comuni strumenti da riga di comando *nix che vorrai conoscere per leggere e manipolare i tuoi file di registro.

• il cat è forse il più semplice. Stampa l'intero file nel flusso di output. Ad esempio, il comando seguente stamperà logfile1 sulla console:

   cat logfile1

• > il carattere consente all'utente di reindirizzare l'output, ad esempio in un altro file. Apre il flusso di destinazione in modalità di scrittura (che significa cancellare i contenuti di destinazione). Ecco come sostituiamo i contenuti di tmpfile con i contenuti di logfile1 :

   cat logfile1 > tmpfile

• >> reindirizza l'output e apre il flusso di destinazione in modalità append. Il contenuto corrente del file di destinazione verrà mantenuto, nuove righe verranno aggiunte in fondo. Questo aggiungerà il contenuto di logfile1 a tmpfile :

   cat logfile1 >> tmpfile

• grep filtra il file in base a un modello e stampa solo le righe corrispondenti. Il comando seguente stamperà solo le righe di logfile1 contenenti il ​​messaggio Bingo :

   grep Bingo logfile1

• cut stampa il contenuto di una singola colonna (per numero a partire da 1). Per impostazione predefinita, ricerca i caratteri di tabulazione come delimitatori tra le colonne. Ad esempio, se hai un file pieno di timestamp nel formato YYYY-MM-DD HH:MM:SS , questo ti consentirà di stampare solo gli anni:

   cut -d"-" -f1 logfile1

• head visualizza solo le prime righe di un file

• tail mostra solo le ultime righe di un file

• sort ordina le righe nell'output

• uniq filtra le righe duplicate

• wc conta le parole (o le righe se usato con il flag -l )

• | (cioè il simbolo della "tubo") fornisce l'output da un comando come input al successivo. Pipe è molto comodo per combinare i comandi. Ad esempio, ecco come possiamo trovare i mesi del 2014 che si verificano all'interno di una serie di timestamp:

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

Qui abbiniamo prima le righe all'espressione regolare "inizia con il 2014", quindi tagliamo i mesi. Infine, utilizziamo la combinazione di sort e uniq per stampare le occorrenze solo una volta.