Holen Sie das Beste aus Ihren PHP-Protokolldateien heraus: Ein praktischer Leitfaden

Veröffentlicht: 2022-03-11

Man könnte zu Recht sagen, dass Protokolle eines der am meisten unterschätzten und am wenigsten genutzten Werkzeuge sind, die einem freiberuflichen PHP-Entwickler zur Verfügung stehen. Trotz der Fülle an Informationen, die sie bieten können, ist es nicht ungewöhnlich, dass Protokolle der letzte Ort sind, an dem ein Entwickler nachsieht, wenn er versucht, ein Problem zu lösen.

Tatsächlich sollten PHP-Logdateien in vielen Fällen der erste Ort sein, an dem nach Hinweisen gesucht wird, wenn Probleme auftreten. Oftmals können die darin enthaltenen Informationen die Zeit, die Sie damit verbringen, sich die Haare auszureißen, um einen knorrigen Fehler aufzuspüren, erheblich reduzieren.

Aber vielleicht noch wichtiger ist, dass Ihre Protokolldateien mit ein wenig Kreativität und Voraussicht als wertvolle Quelle für Nutzungsinformationen und Analysen genutzt werden können. Die kreative Verwendung von Protokolldateien kann helfen, Fragen zu beantworten wie: Welche Browser werden am häufigsten verwendet, um meine Website zu besuchen? Was ist die durchschnittliche Antwortzeit von meinem Server? Wie hoch war der Prozentsatz der Anfragen an den Site-Root? Wie hat sich die Nutzung seit der Bereitstellung der neuesten Updates geändert? Und sehr viel mehr.

PHP-Logdateien

Dieser Artikel enthält eine Reihe von Tipps zur Konfiguration Ihrer Protokolldateien sowie zur Verarbeitung der darin enthaltenen Informationen, um den von ihnen bereitgestellten Nutzen zu maximieren.

Obwohl sich dieser Artikel technisch auf die Protokollierung für PHP-Entwickler konzentriert, sind viele der hier präsentierten Informationen ziemlich technologieunabhängig und auch für andere Sprachen und Technologie-Stacks relevant.

Hinweis: Dieser Artikel setzt grundlegende Vertrautheit mit der Unix-Shell voraus. Für diejenigen, denen dieses Wissen fehlt, wird ein Anhang bereitgestellt, der einige der Befehle vorstellt, die für den Zugriff auf und das Lesen von Protokolldateien auf einem Unix-System erforderlich sind.

Unser PHP-Logdatei-Beispielprojekt

Als Beispielprojekt für Diskussionszwecke in diesem Artikel nehmen wir Symfony Standard als funktionierendes Projekt und richten es auf Debian 7 Wheezy mit rsyslogd , nginx und PHP-FPM ein.

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

Dadurch erhalten wir schnell ein funktionierendes Testprojekt mit einer schönen Benutzeroberfläche.

Tipps zum Konfigurieren Ihrer Protokolldateien

Hier sind einige Hinweise, wie Sie Ihre Protokolldateien konfigurieren können, um ihren Wert zu maximieren.

Konfiguration des Fehlerprotokolls

Fehlerprotokolle stellen die grundlegendste Form der Protokollierung dar; dh zusätzliche Informationen und Details erfassen, wenn Probleme auftreten. In einer idealen Welt möchten Sie also, dass keine Fehler auftreten und Ihre Fehlerprotokolle leer sind. Aber wenn Probleme auftreten (was immer der Fall ist), sollten Ihre Fehlerprotokolle einer der ersten Stopps sein, die Sie auf Ihrem Debugging-Trail machen.

Fehlerprotokolle sind in der Regel recht einfach zu konfigurieren.

Zum einen können alle Fehler- und Absturzmeldungen in genau demselben Format im Fehlerprotokoll protokolliert werden, in dem sie sonst einem Benutzer präsentiert würden. Mit einer einfachen Konfiguration muss der Endbenutzer diese hässlichen Fehlerspuren auf Ihrer Website nie sehen, während Entwickler immer noch in der Lage sind, das System zu überwachen und diese Fehlermeldungen in all ihren blutigen Details zu überprüfen. So richten Sie diese Art der Protokollierung in PHP ein:

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

Zwei weitere Zeilen, die unbedingt in eine Protokolldatei für eine Live-Site aufgenommen werden müssen, um zu verhindern, dass den Benutzern blutige Fehlerdetails angezeigt werden, sind:

 display_errors = Off display_startup_errors = Off

Systemprotokoll ( syslog ) Konfiguration

Es gibt viele allgemein kompatible Implementierungen des syslog -Daemons in der Open-Source-Welt, darunter:

  • syslogd und sysklogd – am häufigsten auf Systemen der BSD-Familie, CentOS, Mac OS X und anderen zu sehen
  • syslog-ng – Standard für moderne Gentoo- und SuSE-Builds
  • rsyslogd – weit verbreitet in den Betriebssystemfamilien Debian und Fedora

(Hinweis: In diesem Artikel verwenden wir rsyslogd für unsere Beispiele.)

Die grundlegende Syslog-Konfiguration ist im Allgemeinen ausreichend, um Ihre Protokollmeldungen in einer systemweiten Protokolldatei zu erfassen (normalerweise /var/log/syslog ; kann je nach Distribution auch /var/log/messages oder /var/log/system.log Sie verwenden).

Das Systemprotokoll bietet mehrere Protokollfunktionen, von denen acht ( LOG_LOCAL0 bis LOG_LOCAL7 ) für von Benutzern bereitgestellte Projekte reserviert sind. So könnten Sie beispielsweise LOG_LOCAL0 so einrichten, dass es basierend auf der Protokollierungsebene (dh Fehler, Warnung, Info, Debug) in 4 separate Protokolldateien schreibt:

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

Wenn Sie jetzt eine Protokollnachricht in die Einrichtung LOG_LOCAL0 schreiben, werden die Fehlermeldungen in LOG_LOCAL0 /var/log/my/err.log , Warnmeldungen in /var/log/my/warning.log und so weiter. Beachten Sie jedoch, dass der Syslog-Daemon Nachrichten für jede Datei basierend auf der Regel „diese Stufe und höher“ filtert. Im obigen Beispiel erscheinen also alle Fehlermeldungen in allen vier konfigurierten Dateien, Warnmeldungen erscheinen in allen außer dem Fehlerprotokoll, Info-Meldungen erscheinen in den Info- und Debug-Logs und Debug-Meldungen werden nur in debug.log .

Ein weiterer wichtiger Hinweis; Die - Zeichen vor den Info- und Debug-Level-Dateien im obigen Konfigurationsdateibeispiel zeigen an, dass Schreibvorgänge in diese Dateien asynchron ausgeführt werden sollten (da diese Operationen nicht blockieren). Dies ist normalerweise in Ordnung (und in den meisten Situationen sogar empfohlen) für Info- und Debug-Protokolle, aber es ist am besten, wenn Schreibvorgänge in das Fehlerprotokoll (und höchstwahrscheinlich auch in das Warnungsprotokoll) synchron sind.

Um eine weniger wichtige Protokollierungsebene (z. B. auf einem Produktionsserver) abzuschalten, können Sie zugehörige Nachrichten einfach nach /dev/null (d. h. ins Nirgendwo) umleiten:

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

Eine spezifische Anpassung, die nützlich ist, insbesondere um einige der PHP-Protokolldateianalysen zu unterstützen, die wir später in diesem Artikel besprechen werden, ist die Verwendung von Tabulatoren als Trennzeichen in Protokollmeldungen. Dies kann einfach durch Hinzufügen der folgenden Datei in /etc/rsyslog.d :

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

Und schließlich vergessen Sie nicht, den Syslog-Daemon neu zu starten, nachdem Sie Konfigurationsänderungen vorgenommen haben, damit sie wirksam werden:

 service rsyslog restart

Konfiguration des Serverprotokolls

Im Gegensatz zu beschreibbaren Anwendungslogs und Fehlerlogs werden Serverlogs ausschließlich von den entsprechenden Server-Daemons (zB Webserver, Datenbankserver etc.) bei jeder Anfrage geschrieben. Die einzige „Kontrolle“, die Sie über diese Protokolle haben, besteht in dem Umfang, in dem der Server Ihnen erlaubt, seine Protokollierungsfunktionalität zu konfigurieren. Obwohl es in diesen Dateien eine Menge zu durchsuchen gibt, sind sie oft die einzige Möglichkeit, ein klares Gefühl dafür zu bekommen, was „unter der Haube“ Ihres Servers vor sich geht.

Stellen wir unsere Symfony Standard-Beispielanwendung in einer Nginx-Umgebung mit MySQL-Speicher-Backend bereit. Hier ist die nginx-Hostkonfiguration, die wir verwenden werden:

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

In Bezug auf die letzten beiden Anweisungen oben: access_log stellt das allgemeine Anforderungsprotokoll dar, während error_log für Fehler steht, und wie bei Anwendungsfehlerprotokollen lohnt es sich, eine zusätzliche Überwachung einzurichten, um bei Problemen gewarnt zu werden, damit Sie schnell reagieren können.

Hinweis: Dies ist eine absichtlich stark vereinfachte Nginx-Konfigurationsdatei, die nur zu Beispielzwecken bereitgestellt wird. Es achtet fast nicht auf Sicherheit und Leistung und sollte nicht so wie es ist in einer „echten“ Umgebung verwendet werden.

Dies ist, was wir in /var/log/nginx/my_access.log erhalten, nachdem wir http://my.log-sandbox/app_dev.php/ in den Browser eingegeben und die Enter gedrückt haben.

 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"

Dies zeigt, dass der Browser zum Bereitstellen einer Seite tatsächlich 9 HTTP-Aufrufe durchführt. 7 davon sind jedoch Anforderungen an statische Inhalte, die einfach und leichtgewichtig sind. Sie nehmen jedoch immer noch Netzwerkressourcen in Anspruch, und dies kann durch die Verwendung verschiedener Sprites und Minifizierungstechniken optimiert werden.

Während diese Optimierungen in einem anderen Artikel diskutiert werden sollen, ist hier relevant, dass wir Anforderungen an statische Inhalte separat protokollieren können, indem wir eine andere location für sie verwenden:

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

Denken Sie daran, dass nginx location einen einfachen Abgleich regulärer Ausdrücke durchführt, sodass Sie so viele statische Inhaltserweiterungen einschließen können, wie Sie erwarten, dass sie auf Ihrer Website versendet werden.

Das Analysieren solcher Protokolle unterscheidet sich nicht vom Analysieren von Anwendungsprotokollen.

Andere erwähnenswerte Protokolle

Zwei weitere erwähnenswerte PHP-Protokolle sind das Debug-Protokoll und das Datenspeicherprotokoll.

Das Debug-Log

Eine weitere praktische Sache bei Nginx-Protokollen ist das Debug-Protokoll. Wir können es aktivieren, indem wir die error_log -Zeile der Konfiguration durch Folgendes ersetzen (erfordert, dass das nginx-Debug-Modul installiert ist):

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

Die gleiche Einstellung gilt für Apache oder einen anderen von Ihnen verwendeten Webserver.

Übrigens haben Debug-Protokolle nichts mit Fehlerprotokollen zu tun, obwohl sie in der error_log Direktive konfiguriert sind.

Obwohl das Debug-Protokoll tatsächlich ausführlich sein kann (eine einzelne Nginx-Anfrage hat beispielsweise 127 KB an Protokolldaten generiert!), kann es dennoch sehr nützlich sein. Das Durchsuchen einer Protokolldatei kann umständlich und mühsam sein, aber es kann oft schnell Hinweise und Informationen liefern, die den Debugging-Prozess erheblich beschleunigen.

Insbesondere das Debug-Protokoll kann beim Debuggen von Nginx-Konfigurationen sehr hilfreich sein, insbesondere bei den kompliziertesten Teilen wie location und rewrite Ketten.

Natürlich sollten Debug-Protokolle niemals in einer Produktionsumgebung aktiviert werden. Die Menge an Speicherplatz, die sie verwenden, und die Menge an Informationen, die sie speichern, bedeuten eine große I/O-Last auf Ihrem Server, was die Leistung des gesamten Systems erheblich beeinträchtigen kann.

Datenspeicherprotokolle

Eine andere Art von Serverprotokoll (nützlich zum Debuggen) sind Datenspeicherprotokolle. In MySQL können Sie sie aktivieren, indem Sie diese Zeilen hinzufügen:

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

Diese Protokolle enthalten einfach eine Liste von Abfragen, die vom System ausgeführt werden, während Datenbankanforderungen in chronologischer Reihenfolge verarbeitet werden, was für verschiedene Debugging- und Tracing-Anforderungen hilfreich sein kann. Sie sollten jedoch auf Produktionssystemen nicht aktiviert bleiben, da sie zusätzliche unnötige E/A-Last erzeugen, die sich auf die Leistung auswirkt.

Schreiben in Ihre Protokolldateien

PHP selbst bietet Funktionen zum Öffnen, Schreiben und Schließen von Protokolldateien ( openlog() , syslog() bzw. closelog() ).

Es gibt auch zahlreiche Protokollierungsbibliotheken für PHP-Entwickler, wie Monolog (beliebt bei Symfony- und Laravel-Benutzern), sowie verschiedene Framework-spezifische Implementierungen, wie die in CakePHP integrierten Protokollierungsfunktionen. Im Allgemeinen verpacken Bibliotheken wie Monolog nicht nur syslog() -Aufrufe, sondern ermöglichen auch die Verwendung anderer Backend-Funktionen und -Tools.

Hier ist ein einfaches Beispiel für das Schreiben in das Protokoll:

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

Unser Aufruf hier an openlog :

  • konfiguriert PHP so, dass jeder Systemprotokollnachricht während der Lebensdauer des Skripts eine eindeutige Kennung vorangestellt wird
  • setzt es so, dass das Öffnen der Syslog-Verbindung verzögert wird, bis der erste Aufruf von syslog() stattgefunden hat
  • legt LOG_LOCAL0 als Standardprotokollierungseinrichtung fest

So würde der Inhalt der Protokolldatei nach dem Ausführen des obigen Codes aussehen:

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

Maximieren Sie den Wert Ihrer PHP-Protokolldateien

Nun, da wir alle mit Theorie und Grundlagen vertraut sind, wollen wir sehen, wie viel wir aus Protokollen herausholen können, wenn wir so wenig Änderungen wie möglich an unserem Symfony Standard-Beispielprojekt vornehmen.

Zuerst erstellen wir die Skripte src/log-begin.php (um unsere Protokolle richtig zu öffnen und zu konfigurieren) und src/log-end.php (um Informationen über den erfolgreichen Abschluss zu protokollieren). Beachten Sie, dass wir der Einfachheit halber alle Meldungen in das Infolog schreiben.

 # 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');

Und lassen Sie uns diese Skripte 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');

Für die Entwicklungsumgebung wollen wir diese Skripte auch in app_dev.php fordern. Der Code dafür wäre derselbe wie oben, außer dass wir MODE auf DEV und nicht auf PROD .

Wir möchten auch verfolgen, welche Controller aufgerufen werden, also fügen wir eine weitere Zeile in Acme\DemoBundle\EventListener\ControllerListener , direkt am Anfang der Methode ControllerListener::onKernelController() :

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

Beachten Sie, dass diese Änderungen lediglich 15 zusätzliche Codezeilen ausmachen, aber insgesamt eine Fülle von Informationen liefern können.

Analysieren der Daten in Ihren Protokolldateien

Sehen wir uns zunächst an, wie viele HTTP-Anforderungen erforderlich sind, um jeden Seitenladevorgang zu bedienen.

Hier sind die Informationen in den Protokollen für eine Anfrage, basierend auf der Art und Weise, wie wir unsere Protokollierung konfiguriert haben:

 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

Jetzt wissen wir also, dass jeder Seitenladevorgang tatsächlich mit zwei HTTP-Anforderungen bedient wird.

Eigentlich sind hier zwei Punkte erwähnenswert. Erstens dienen die zwei Anfragen pro Seitenladevorgang der Verwendung von Symfony im Entwicklermodus (was ich in diesem Artikel getan habe). Sie können Aufrufe im Entwicklungsmodus identifizieren, indem Sie nach /app-dev.php/ URL-Blöcken suchen. Nehmen wir zweitens an, dass jeder Seitenladevorgang mit zwei aufeinanderfolgenden Anfragen an die Symfony-App bedient wird. Wie wir zuvor in den nginx-Zugriffsprotokollen gesehen haben, gibt es tatsächlich mehr HTTP-Aufrufe, von denen einige für statische Inhalte bestimmt sind.

OK, jetzt surfen wir ein bisschen auf der Demoseite (um die Daten in den Protokolldateien aufzubauen) und sehen wir uns an, was wir sonst noch aus diesen Protokollen lernen können.

Wie viele Anfragen wurden seit Beginn der Protokolldatei insgesamt bedient?

 # grep -c BEGIN info.log 10

Ist einer von ihnen fehlgeschlagen (wurde das Skript beendet, ohne das Ende zu erreichen)?

 # grep -c END info.log 10

Wir sehen, dass die Anzahl der BEGIN und END Datensätze übereinstimmen, was uns sagt, dass alle Aufrufe erfolgreich waren. (Wenn das PHP-Skript nicht erfolgreich abgeschlossen worden wäre, hätte es die Ausführung des Skripts src/log-end.php nicht erreicht.)

Wie hoch war der Prozentsatz der Anfragen an den Site-Root?

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

Dies sagt uns, dass es 2 Seitenladevorgänge des Site-Roots gab. Da wir zuvor erfahren haben, dass (a) es 2 Anfragen an die App pro Seitenladevorgang gibt und (b) es insgesamt 10 HTTP-Anfragen gab, betrug der Prozentsatz der Anfragen an den Site-Root 40 % (d. h. 2 x 2/10).

Welche Controller-Klasse ist für die Bereitstellung von Anforderungen an den Standortstamm verantwortlich?

 # 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

Hier haben wir die eindeutige ID einer Anfrage verwendet, um alle Protokollmeldungen zu dieser einzelnen Anfrage zu überprüfen. Dadurch konnten wir feststellen, dass die Controller-Klasse, die für das Zustellen von Anforderungen an den Standortstamm verantwortlich ist, Acme\DemoBundle\Controller\WelcomeController ist.

Welche Clients mit IPs des Subnetzes 192.168.0.0/16 haben auf die Site zugegriffen?

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

Wie in diesem einfachen Testfall erwartet, hat nur mein Host-Computer auf die Site zugegriffen. Dies ist natürlich ein sehr vereinfachtes Beispiel, aber die Fähigkeit, die es demonstriert (in der Lage zu sein, die Quellen des Verkehrs auf Ihrer Website zu analysieren), ist offensichtlich ziemlich leistungsfähig und wichtig.

Wie viel Traffic auf meiner Website stammt von FireFox?

Mit 1b101cd als Hash meines Firefox User-Agent kann ich diese Frage wie folgt beantworten:

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

Antwort: 80 % (dh 8/10)

Wie hoch ist der Prozentsatz der Anfragen, die zu einer langsamen Antwort geführt haben?

Für die Zwecke dieses Beispiels definieren wir „langsam“ als mehr als 5 Sekunden, um eine Antwort zu geben. Entsprechend:

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

Antwort: 20 % (dh 2/10)

Hat jemand jemals GET-Parameter angegeben?

 # grep URI info.log | grep \?

Nein, der Symfony-Standard verwendet nur URL-Slugs, also sagt uns das hier auch, dass niemand versucht hat, die Seite zu hacken.

Dies sind nur einige wenige relativ rudimentäre Beispiele dafür, wie Protokolldateien kreativ genutzt werden können, um wertvolle Nutzungsinformationen und sogar grundlegende Analysen zu erhalten.

Andere Dinge, die Sie beachten sollten

Dinge sicher halten

Ein weiteres Heads-up betrifft die Sicherheit. Sie denken vielleicht, dass das Protokollieren von Anfragen eine gute Idee ist, in den meisten Fällen ist dies tatsächlich der Fall. Es ist jedoch wichtig, äußerst vorsichtig zu sein, wenn es darum geht, potenziell sensible Benutzerinformationen zu entfernen, bevor sie im Protokoll gespeichert werden.

Kampf gegen das Aufblähen von Protokolldateien

Da Protokolldateien Textdateien sind, an die Sie immer Informationen anhängen , wachsen sie ständig. Da dies ein bekanntes Problem ist, gibt es einige ziemlich standardmäßige Ansätze, um das Wachstum von Protokolldateien zu kontrollieren.

Am einfachsten ist es, die Stämme zu drehen . Rundholz bedeutet:

  • Regelmäßiges Ersetzen des Protokolls durch eine neue leere Datei zum weiteren Schreiben
  • Speichern der alten Datei für den Verlauf
  • Entfernen von Dateien, die ausreichend „gealtert“ sind, um Speicherplatz freizugeben
  • Stellen Sie sicher, dass die Anwendung ohne Unterbrechung in die Protokolle schreiben kann, wenn diese Dateiänderungen auftreten

Die gebräuchlichste Lösung dafür ist logrotate , das mit den meisten *nix-Distributionen vorinstalliert geliefert wird. Sehen wir uns eine einfache Konfigurationsdatei zum Rotieren unserer Protokolle an:

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

Ein weiterer, fortschrittlicherer Ansatz besteht darin, rsyslogd dazu zu bringen, Nachrichten in Dateien zu schreiben, die basierend auf dem aktuellen Datum und der aktuellen Uhrzeit dynamisch erstellt werden. Dies würde immer noch eine benutzerdefinierte Lösung zum Entfernen älterer Dateien erfordern, ermöglicht es Entwicklern jedoch, Zeitrahmen für jede Protokolldatei genau zu verwalten. Für unser Beispiel:

 $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

Auf diese Weise rsyslog jede Stunde eine individuelle Protokolldatei, und es besteht keine Notwendigkeit, sie zu rotieren und den Daemon neu zu starten. So können Protokolldateien, die älter als 5 Tage sind, entfernt werden, um diese Lösung zu erreichen:

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

Remote-Protokolle

Wenn das Projekt wächst, wird das Analysieren von Informationen aus Protokollen immer ressourcenintensiver. Dies bedeutet nicht nur die Schaffung zusätzlicher Serverlast; Es bedeutet auch, dass zu Zeiten, in denen Sie Protokolle parsen, Spitzenlasten auf der CPU und den Festplattenlaufwerken erzeugt werden, was die Antwortzeit des Servers für Benutzer verkürzen kann (oder im schlimmsten Fall sogar die Website zum Erliegen bringen kann).

Erwägen Sie zur Lösung dieses Problems die Einrichtung eines zentralisierten Protokollierungsservers . Alles, was Sie dazu brauchen, ist eine weitere Box mit geöffnetem UDP-Port 514 (Standard). Damit rsyslogd auf Verbindungen lauscht, fügen Sie die folgende Zeile zu seiner Konfigurationsdatei hinzu:

 $UDPServerRun 514

Damit ist die Einrichtung des Clients so einfach wie:

 *.* @HOSTNAME:514

(wobei HOSTNAME der Hostname Ihres entfernten Protokollierungsservers ist).

Fazit

Während dieser Artikel einige der kreativen Möglichkeiten aufgezeigt hat, wie Protokolldateien viel wertvollere Informationen bieten können, als Sie sich vielleicht bisher vorgestellt haben, ist es wichtig zu betonen, dass wir nur an der Oberfläche dessen gekratzt haben, was möglich ist. Das Ausmaß, der Umfang und das Format dessen, was Sie protokollieren können, ist nahezu unbegrenzt. Das bedeutet, dass Sie – wenn Sie Nutzungs- oder Analysedaten aus Ihren Protokollen extrahieren möchten – diese einfach so protokollieren müssen, dass sie später einfach analysiert und analysiert werden können. Darüber hinaus kann diese Analyse oft mit standardmäßigen Linux-Befehlszeilentools wie grep , sed oder awk durchgeführt werden.

In der Tat sind PHP-Protokolldateien ein äußerst leistungsfähiges Werkzeug, das von enormem Nutzen sein kann.

Ressourcen

Code auf GitHub: https://github.com/isanosyan/toptal-blog-logs-post-example

Anhang: Protokolldateien in der Unix-Shell lesen und bearbeiten

Hier ist eine kurze Einführung in einige der gebräuchlicheren *nix-Befehlszeilentools, mit denen Sie sich zum Lesen und Bearbeiten Ihrer Protokolldateien vertraut machen sollten.

  • cat ist vielleicht die einfachste. Es druckt die gesamte Datei in den Ausgabestrom. Der folgende Befehl gibt beispielsweise logfile1 auf der Konsole aus:

     cat logfile1

  • > Zeichen ermöglicht es dem Benutzer, die Ausgabe umzuleiten, beispielsweise in eine andere Datei. Öffnet den Zielstream im Schreibmodus (was bedeutet, dass der Zielinhalt gelöscht wird). So ersetzen wir den Inhalt von tmpfile durch den Inhalt von logfile1 :

     cat logfile1 > tmpfile

  • >> Leitet die Ausgabe um und öffnet den Zielstream im Anfügemodus. Der aktuelle Inhalt der Zieldatei wird beibehalten, neue Zeilen werden unten hinzugefügt. Dadurch wird der Inhalt von logfile1 an tmpfile :

     cat logfile1 >> tmpfile

  • grep filtert die Datei nach einem bestimmten Muster und gibt nur übereinstimmende Zeilen aus. Der folgende Befehl druckt nur Zeilen von logfile1 , die die Bingo -Nachricht enthalten:

     grep Bingo logfile1

  • cut druckt den Inhalt einer einzelnen Spalte (nach Nummer beginnend bei 1). Sucht standardmäßig nach Tabulatorzeichen als Trennzeichen zwischen Spalten. Wenn Sie beispielsweise eine Datei voller Zeitstempel im Format YYYY-MM-DD HH:MM:SS haben, können Sie nur Jahre drucken:

     cut -d"-" -f1 logfile1

  • head zeigt nur die ersten Zeilen einer Datei an

  • tail zeigt nur die letzten Zeilen einer Datei an

  • sort sortiert Zeilen in der Ausgabe

  • uniq filtert doppelte Zeilen heraus

  • wc zählt Wörter (oder Zeilen, wenn es mit dem Flag -l verwendet wird)

  • | (dh das „Pipe“-Symbol) liefert die Ausgabe von einem Befehl als Eingabe für den nächsten. Pipe ist sehr praktisch zum Kombinieren von Befehlen. So können wir zum Beispiel Monate des Jahres 2014 finden, die innerhalb einer Reihe von Zeitstempeln liegen:

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

Hier gleichen wir zuerst die Zeilen mit dem regulären Ausdruck „beginnt mit 2014“ ab und schneiden dann die Monate ab. Schließlich verwenden wir eine Kombination aus sort und uniq , um Vorkommen nur einmal zu drucken.