Logování v PHP: různé možnosti výsledného formátování výstupů

20. 10. 2021
Doba čtení: 11 minut

Sdílet

 Autor: Depositphotos
V poslední třetí části budou popisovány různé možnosti výsledného formátování výstupů, které dokáží výrazně ovlivnit logovanou informaci. Na závěr bude uveden realističtější příklad použití, ze kterého vyplynou možné kombinace.

2.7. Formátovače

Jak už víme z dřívějška, handlery používají formátovače, aby pro ně vhodně vyfiltrovaly a následně zformátovaly výslednou podobu logované informace. V předchozích ukázkách již byly uvedeny některé z možností formátování a v této části budou probrány důkladněji.

Důležité je uvědomit si, že je možné filtrovat (tj. vybírat jen určité položky z celého logovacího záznamu) a formátovat pouze existující obsah logovacího záznamu, tzn. pouze ty informace, které jsou v něm dostupné.

Jak již víme, každý handler má v sobě i formátovač. Zřídkakdy nám však vyhoví jeho výchozí nastavení, takže používáme jeden z dále uvedených předpřipravených vzorů. Těch existuje, stejně jako u handlerů, značné množství. Jedná se o 15 formátovačů, ale, opět stejně jako u handlerů, je mnoho z nich určeno jen pro speciální použití v konkrétních systémech třetích stran.

2.7.1. Co lze formátovat

Jak již bylo řečeno, jsou to výhradně jednotlivé položky logovacího záznamu, které se adresují jako %polozka% . Připomeňme si jejich konkrétní jména:

%level% %level_name% %channel% %datetime% %message% %context% %extra%

Filtrování znamená, že některé z těchto položek vůbec do formátu výstupu neuvedeme, a tak se ve výstupu nakonec neobjeví. Typicky se např. vynechává %level%, což je málo vypovídající celé číslo.

Formátování znamená, že pořadí explicitně uvedených položek můžeme libovolně míchat a položky doplňovat / oddělovat dalšími znaky apod.

Vlastní obsah položek se vypisuje tak, jak je uveden v logovacím záznamu, s jedinou výjimkou. Jediná položka, kterou lze vnitřně dále konfigurovat, je  %datetime%

Její výchozí formát je Y-m-d\TH:i:sP , což dává např.:

2021-09-06T21:15:03.047516+02:00

Pro naše vlastní formátování se použijí vzory („formátovací řetězce“) z dokumentace DateTime::format.

např.: Y-m-d H:i:s , což dává např. běžně užívaný formát data a času:

2021-09-06 21:15:03

Tento formátovací řetězec se pak zadává jako volitelný parametr u různých formátovačů.

2.7.2. LineFormatter

Je to nejčastěji používaný formátovač, který zajistí formátování údajů do textové řádky.

Dovoluje nastavit libovolnou kombinaci položek z logovacího záznamu a použít vlastní formát pro %datetime%.

Jeho typické použití je:

$dateFormat = "Y-m-d H:i:s";
$zaznam = "%datetime% > %channel% > %level_name% \n";
$formatter = new LineFormatter($zaznam, $dateFormat);
$handler->setFormatter($formatter);

Což vypíše např.:

2021-04-30 15:44:22 > soubor > INFO

2.7.3. HtmlFormatter

Chceme-li co s nejmenším úsilím vypisovat logovací záznamy v HTML formátu postupně do tabulky, použijeme tento formátovač.

Bohužel, jednoduchost jeho použití je často velmi omezující, protože nedovoluje filtrovat ani upravovat formátování. To znamená, že se nedá vůbec ovlivnit pořadí a množství vypisovaných položek. Jediné, co lze ovlivnit, je jen formát  %datetime%.

Jeho typické použití je:

$dateFormat = "Y-m-d H:i:s";
$handler->setFormatter(new HtmlFormatter($dateFormat));

$logger->info('zpráva log-info');
$logger->error('zpráva log-error');
$logger->alert('zpráva log-alert');

Ve výsledném HTML kódu je pouze tabulka, chybí zde hlavička HTML dokumentu, proto je v příkladu kódování zobrazeno chybně. Zobrazí se:


Autor: Pavel Herout

2.7.4. JsonFormatter

Potřebujeme-li zapsat celý logovací záznam do JSON formátu, použijeme tento formátovač. Nedává ale žádné možnosti konfigurace, protože není možné změnit ani pořadí ani počet položek a dokonce ani zadat vlastní formát pro  %datetime%.

Jeho typické použití je:

$jmenoSouboru = __DIR__ . '\..\..\..\logy\souborJsonFormatter.log';
$logger = new Logger('soubor');
$handler = new StreamHandler($jmenoSouboru, Logger::INFO);
$handler->setFormatter(new JsonFormatter());
$logger->pushHandler($handler);
$logger->info('zpráva log-info');

Obsah souboru souborJsonFormatter.log (je provedeno odřádkování pro lepší čitelnost):

{"message":"zpráva log-info","context":{},"level":200,
"level_name":"INFO","channel":"soubor",
"datetime":"2021-09-09T16:54:33.824112+02:00","extra":{}}

3. Rozsáhlejší příklad

Na závěr je uveden syntetický příklad, který ukazuje různé kombinace dříve uvedených dovedností.

Poznámka:
Účelem příkladu je ukázat možnosti logování, nikoliv možnosti či způsoby psaní PHP aplikací.

V příkladu jsou použity dva loggery zapisující do jednoho výstupního souboru priklad.log. Přičemž:

  • $logHlavni
    zachycuje všechny „hlavní“ události běhu aplikace a jeho význam by byl zejména při provozu aplikace
  • $logSoubor
    zachycuje jen události při zpracování souboru a hodil by se ve fázi ladění. Ukazuje:
    • použití dvou handlerů – do konzole a do souboru priklad.log
    • využití IntrospectionProcessor
    • využití doplňkové informace v context při výpisu na konzoli

Příklad by měl mj. demonstrovat skutečnost, že vyladění úrovní logování, volba výstupních souborů a množství zapisované informace není triviální záležitost. Vyžaduje to prvotní rozvržení a pak následné experimenty. Logovacích informací by totiž nemělo být ani moc, ani málo a měly by být relevantní – proto se např. do konzole nevypisuje časová známka.

Popis ovládání aplikace:

Zadá se jméno souboru (implicitní přípona je .txt) následované dvěma parametry najdi a nahrad. V tomto souboru nalezne všechny řetězce s hodnotou najdi a nahradí je hodnotou parametru nahrad. Výsledek zapíše do souboru .out. Okamžitě po provedení záměny je možné stejnou záměnu provádět v jiném souboru, protože parametry najdi a nahrad zůstávají vyplněné i pro další případné kolo. Pokud chceme vyhledávat a/nebo nahrazovat jiné řetězce, je třeba tyto parametry příslušně nastavit.

Soubor index.php je zodpovědný za přípravu a konfiguraci loggerů (jsou předávány přes session) a za zpracování požadavku:

<?php

use Monolog\Formatter\LineFormatter;
use Monolog\Handler\StreamHandler;
use Monolog\Logger;
use Monolog\Handler\BrowserConsoleHandler;
use Monolog\Processor\IntrospectionProcessor;
use app\priklad\Funkce;

require_once('Funkce.php');
require __DIR__ . '/../../../vendor/autoload.php';

session_start();

if (count($_POST) == 0) {
  nastavLogovani();
  (new Funkce())->vypisHtml();
}
else {
  zpracujPozadavek();
}

function nastavLogovani()
{
  $logHlavni = new Logger('hlavni');
  $logSoubor = new Logger('soubor');
  $dateFormat = "Y-m-d H:i:s";

  $handStream = new StreamHandler("priklad.log", Logger::DEBUG);
  $zaznamStream = "%datetime% %channel%.%level_name% %message% %extra% \n";
  $formatterStream = new LineFormatter($zaznamStream, $dateFormat);
  $handStream->setFormatter($formatterStream);

  $handKonzole = new BrowserConsoleHandler(Logger::INFO);
  $zaznamKonzole = "%channel%.%level_name% %message% souhrn=%context%";
  $formatterKonzole = new LineFormatter($zaznamKonzole);
  $handKonzole->setFormatter($formatterKonzole);

  $logSoubor->pushProcessor(new IntrospectionProcessor());

  $logHlavni->pushHandler($handStream);
  $logHlavni->pushHandler($handKonzole);
  $logSoubor->pushHandler($handStream);

  $_SESSION["HLAVNI"] = $logHlavni;
  $_SESSION["SOUBOR"] = $logSoubor;
}

function zpracujPozadavek()
{
  $logHlavni = $_SESSION["HLAVNI"];
  $logHlavni->notice("Zacatek zpracovani");
  $soubor = $_POST["soubor"];
  $najdi = $_POST["najdi"];
  $nahrad = $_POST["nahrad"];
  $funkce = new Funkce();
  $vysledek = $funkce->overParametry($soubor, $najdi, $nahrad);
  $pocet = 0;
  if ($vysledek == true) {
    $pocet = $funkce->provedZamenu($soubor, $najdi, $nahrad);
  }
  $souhrn = array("soubor"=>$soubor, "najdi"=>$najdi,
                   "nahrad"=>$nahrad, "pocet"=>$pocet);
  $logHlavni->notice("Konec zpracovani", $souhrn);
  $funkce->vypisHtml($soubor, $najdi, $nahrad, $pocet);
}

Třída Funkce je zodpovědná za kontrolu parametrů a za náhradu řetězců v daném souboru. Používá oba dva loggery. Pro frontend (metoda vypisHtml()) je z důvodů jednoduchosti použit velmi primitivní návrh.

<?php

namespace app\priklad;

class Funkce
{
  private $logHlavni;
  private $logSoubor;

  public function __construct()
  {
    $this->logHlavni = $_SESSION["HLAVNI"];
    $this->logSoubor = $_SESSION["SOUBOR"];
  }

  public function vypisHtml(string $soubor="", string $najdi="",
                            string $nahrad="", int $pocet=-1) : void
  {
    ?>
    <!doctype html>
    <html>
      <head>
        <meta charset="utf-8">
        <title>Ukázka logování</title>
      </head>
      <body>
        <form action="index.php"
              method="post"
              autocomplete="off">
          <label for="soubor">Jméno souboru bez přípony:</label>
          <input id="soubor" type="text" name="soubor">
          <br>
          <label for="najdi">Najdi:</label>
          <input id="najdi" type="text" name="najdi" value="<?=$najdi?>">
          <br>
          <label for="nahrad">Nahrad:</label>
          <input id="nahrad" type="text" name="nahrad" value="<?=$nahrad?>">
          <br>
          <input type="submit" value="Proveď nahrazení">
        </form>
      <?php
      if ($pocet >= 0) {
        echo "Počet nahrazených řádek v souboru <code>".$soubor.".out</code> = ".$pocet;
      }
      ?>
      </body>
    </html>
    <?php
  }

  public function overParametry(string $soubor, string $najdi,
                                string $nahrad) : bool
  {
    $vysledek = true;
    $vysledek = $vysledek && $this->hodnotaParametru("soubor", $soubor);
    $vysledek = $vysledek && $this->hodnotaParametru("najdi", $najdi);
    $vysledek = $vysledek && $this->hodnotaParametru("nahrad", $nahrad);
    return $vysledek;
  }

  private function hodnotaParametru(string $jmeno, string $hodnota) : bool
  {
    if (strlen($hodnota) > 0) {
      $this->logHlavni->info("Parametr: " . $jmeno ."=". $hodnota);
      return true;
    }
    else {
      $this->logHlavni->warning("Parametr: " . $jmeno ." nenastaven");
      return false;
    }
  }

  public function provedZamenu(string $soubor, string $najdi,
                               string $nahrad) : int
  {
    $jmenoIn = $soubor . ".txt";
    $jmenoOut = $soubor . ".out";

    $radky = $this->nactiSoubor($jmenoIn);
    if (count($radky) == 0) {
      $this->logHlavni->warning("Vstupni soubor:" . $jmenoIn . " neexistuje nebo je prazdny");
      return 0;
    }
    $zameneno = array();
    $pocet = 0;
    foreach ($radky as $radka) {
      $this->logSoubor->debug("Stara:'".$radka."'");
      $nova = str_replace($najdi, $nahrad, $radka);
      $this->logSoubor->debug("Nova :'".$nova."'");
      if ($nova != $radka) {
        $pocet++;
        $this->logSoubor->info("Aktualni pocet nahrazeni:".$pocet);
      }
      array_push($zameneno, $nova."\n");
    }

    file_put_contents($jmenoOut, $zameneno);
    $this->logHlavni->notice("Vystupni soubor:".$jmenoOut);
    $this->logHlavni->info("Celkem zamenenych radek:".$pocet);
    return $pocet;
  }

  private function nactiSoubor(string $jmeno) : array
  {
    if (file_exists($jmeno) == true) {
      $this->logSoubor->info("Vstupni soubor:".$jmeno. " existuje");
    } else {
      $this->logSoubor->warning("Vstupni soubor:".$jmeno. " neexistuje");
      return [];
    }
    $obsah = file_get_contents($jmeno);
    $radky = explode("\n", $obsah);
    $this->logSoubor->info("Celkem radek:".count($radky));

    return $radky;
  }
}

Po spuštění index.php se zobrazí:


Autor: Pavel Herout

Nastavení správných parametrů:


Autor: Pavel Herout

Provedení náhrad:


Autor: Pavel Herout

Obsah souboru vstup.txt

první řádka bez chyby
druhá řádka ERROR s chybou
třetí řádka bez chyby
čtvrtá řádka ERROR s dvojnásobnou chybou ERROR
pátá řádka bez chyby
šestá řádka s chybou ERROR

Výpis v konzoli – poslední log ukazuje využití context pojmenovaného  souhrn


Autor: Pavel Herout

Obsah souboru priklad.log (dlouhé řádky jsou zalomené)

2021-09-09 17:24:43 hlavni.NOTICE Zacatek zpracovani []
2021-09-09 17:24:43 hlavni.INFO Parametr: soubor=vstup []
2021-09-09 17:24:43 hlavni.INFO Parametr: najdi=ERROR []
2021-09-09 17:24:43 hlavni.INFO Parametr: nahrad=AbC []
2021-09-09 17:24:43 soubor.INFO Vstupni soubor:vstup.txt existuje
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":106,"class":"app\\priklad\\Funkce","function":"nactiSoubor"}
2021-09-09 17:24:43 soubor.INFO Celkem radek:7
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":113,"class":"app\\priklad\\Funkce","function":"nactiSoubor"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'první řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'první řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'druhá řádka ERROR s chybou'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'druhá řádka AbC s chybou'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.INFO Aktualni pocet nahrazeni:1
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":92,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'třetí řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'třetí řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'čtvrtá řádka ERROR s dvojnásobnou chybou ERROR'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'čtvrtá řádka AbC s dvojnásobnou chybou AbC'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.INFO Aktualni pocet nahrazeni:2
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":92,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'pátá řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'pátá řádka bez chyby'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:'šestá řádka s chybou ERROR'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :'šestá řádka s chybou AbC'
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.INFO Aktualni pocet nahrazeni:3
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":92,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Stara:''
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":87,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 soubor.DEBUG Nova :''
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":89,"class":"app\\priklad\\Funkce","function":"provedZamenu"}
2021-09-09 17:24:43 hlavni.NOTICE Vystupni soubor:vstup.out []
2021-09-09 17:24:43 hlavni.INFO Celkem zamenenych radek:3 []
2021-09-09 17:24:43 hlavni.NOTICE Konec zpracovani []

Nenastavení parametru Jméno souboru  – výsledek:


Autor: Pavel Herout

Výpis v konzoli:


Autor: Pavel Herout

Pokračující obsah souboru priklad.log:

2021-09-09 17:27:11 hlavni.NOTICE Zacatek zpracovani []
2021-09-09 17:27:11 hlavni.WARNING Parametr: soubor nenastaven []
2021-09-09 17:27:11 hlavni.NOTICE Konec zpracovani []

Nastavení parametru Jméno souboru na jméno neexistujícího souboru  blbost.txt


Autor: Pavel Herout

Výpis v konzoli:

ict ve školství 24


Autor: Pavel Herout

Pokračující obsah souboru priklad.log:

2021-09-09 17:30:52 hlavni.NOTICE Zacatek zpracovani []
2021-09-09 17:30:52 hlavni.INFO Parametr: soubor=blbost []
2021-09-09 17:30:52 hlavni.INFO Parametr: najdi=ERROR []
2021-09-09 17:30:52 hlavni.INFO Parametr: nahrad=AbC []
2021-09-09 17:30:52 soubor.WARNING Vstupni soubor:blbost.txt neexistuje
{"file":"C:\\xampp\\htdocs\\logovani\\src\\app\\priklad\\Funkce.php","line":108,"class":"app\\priklad\\Funkce","function":"nactiSoubor"}
2021-09-09 17:30:52 hlavni.WARNING Vstupni soubor:blbost.txt neexistuje nebo je prazdny []
2021-09-09 17:30:52 hlavni.NOTICE Konec zpracovani []

Závěr

Toto bylo stručné seznámení s možnostmi logování. Máte-li zkušenosti s jinými knihovnami nebo s jinými postupy, prosím, napište je do diskuze.

Autor článku

Pracuje na Katedře informatiky a výpočetní techniky Fakulty aplikovaných věd na Západočeské univerzitě v Plzni, zabývá se programovacími jazyky, softwarovými technologiemi a testováním.