13 May

Logfájlok pokla 2. - MDC keretrendszer alatt


Az előző cikkben arról volt szó, hogy is tudjuk elszeparálni az egyes logbejegyzéseket az apache loggerével. Mint kiderült, van hasonló funkcionalitás a monologban is, csak ott még nem volt ekkora ráhatása Martin Fowlernek és társainak, mert nem MDC néven, hanem processor néven tudunk belenyúlni és plusz információkkal kiegészíteni az egyes bejegyzéseket. Első körben a Laravelt fogjuk megvizsgálni ezen szempontból, mégpedig az 5.4-es verzióját.

 Az iménti monologos dolog után persze használhatnánk azt is, de abból a szempontból is tanulságos lehet a cikk, hogy mennyire könnyű vagy épp nehéz kicserélni egy ilyen dolgot. Telepítsük először a Laravelt egy mappába:

composer create-project laravel/laravel "5.4"

ezután navigáljunk bele és  jöhet a logger is a helyére:
composer require apache/log4php : "^2.3"

Most, hogy megvannak a dolgok, akkor jöhet az, hogy bekonfiguráljuk a LoggerMDC-t.  De mégis hol tegyünk ilyet? Mivel nem egy külön csomagban akarjuk ezt megvalósítani, ezért jelen esetben kerüljön az AppServiceProvider boot metódusába:
class AppServiceProvider extends ServiceProvider
{
    /**
     * Bootstrap any application services.
     *
     * @return void
     */
    public function boot()
    {
        \Logger::configure("config/logger.php");
        $logger = \Logger::getLogger("main");
        Log::swap($logger);
    }

Na akkor most 

A bootstrap során a következők történnek. Először is megadjuk a konfiguráció helyét az apache loggerének. Ezt a Laravel által már megszokott helyre tettük, a config mappába, mindjárt megnézzük a tartalmát is. Ha ez megtörtént, akkor a statikus factory-ból kikérünk egy logger példányt. Ezután jön az igazi mágia, amikor azt mondjuk a Log facade-nek, hogy ugyan cserélje már ki a facade mögött található objektumot arra, amit átadunk. Ez elég veszélyes játszma, ugyanis nincs rá garancia, hogy ami objektumot átadunk, az képes lesz ellátni azt a feladatot, mint amire hivatott, lévén semmiféle típusellenőrzés nincs, nem kell interfészeknek megfelelnünk, se semmi, ugyanis mindenféle call és callStatic-ekkel kerül megoldásra mindez. Viszont az igen nagy szerencse ebben az esetben, hogy a két logger, a monolog és a log4php közel ugyanolyan metódusokkal van felvértezve, ezért a kódunkat nem nagyon tudjuk megfektetni, habár ez a megoldás közel sem szép. Most akkor nézzük meg a konfigurációt:
return array(
    'appenders' => array(
        'default' => array(
            'class' => 'LoggerAppenderFile',
            'layout' => array(
                'class' => 'LoggerLayoutPattern',
                'params' => array(
                    'conversionPattern' => '%date [%logger] [%-5level] [%mdc{guid}] %msg%n'
                )
            ),
            'params' => array(
                'file' => 'storage/logs/laravel.log',
                'append' => true
            ),
        ),
    ),
    'rootLogger' => array(
        'appenders' => array('default'),
    )
);

Nagyban hasonlít az előző cikkben írtakhoz, a fájl elérési útját leszámítva, amit ugyanis a laravel default logjához állítottunk be, hogy ez ne változzon. Akkor most jön az, hogy hol kellene az MDC értékét beálítani? Nos ezt egy middlewareben kellene megejtenünk, úgyhogy hozzunk is léttre egy UserAware middleware-t erre a célra. Ez annyit fog csinálni, hogy a sütik közül a guid-ot kiszedi és beállítja az MDC-k közé.
public function handle($request, \Closure $next)
{

    \LoggerMDC::put("guid",$request->cookie("laravel_session"));

    return $next($request);
}

Az egyszerűség kedvéért most a laravel session értékét fogjuk használni, így nem kell külön sütit létrehoznunk és beállítgatnunk. Akkor már csak egy olyan route kell, ahol használjuk ezt a middleware-t. Vegyük fel a web-es middleware groupba mindezt a app/Http/Kernel.php - ban:
protected $middlewareGroups = [
    'web' => [
        \App\Http\Middleware\EncryptCookies::class,
        \Illuminate\Cookie\Middleware\AddQueuedCookiesToResponse::class,
        \Illuminate\Session\Middleware\StartSession::class,
        \Illuminate\View\Middleware\ShareErrorsFromSession::class,
        \App\Http\Middleware\VerifyCsrfToken::class,
        \Illuminate\Routing\Middleware\SubstituteBindings::class,
        UserAware::class
    ],

Ezután minden routes/web.php-ben létrehozott route-ra érvényes lesz ez a middleware is, így nincs más dolgunk, mint a gyári welcome page-et kiegészíteni:
Route::get('/', function () {
    Log::info("teszt");
    return view('welcome');
});

Ezután ha meglőjük a főoldalt, már láthatjuk is a logbejegyzéseket:
2017-05-12T22:01:42+00:00 [main] [INFO] [WTWlh1oaFTpSO0tFzCMScpYZNkgtlQ8fKxPOeygk] teszt

Nem is volt olyan nehéz, ugye? Viszont a megoldás továbbra sem szép, de annak érdekében, hogy generikus megoldást hozzunk a rendszerbe (ezáltal a kivételek is ezzel legyenek logolva), ami pl. képes az exception-ök kezelésére is, sajnos le kell cseréljük a loggert. Viszont mágia ide vagy oda, a nap végén nekünk adott egy Logger osztályunk, amire rá akarunk húzni egy LoggerInterface-t. A Log facade az alábbi statikus metódusokkal rendelkezik, amiket egy az egyben delegál az elburkolt osztály nem-statikus metódusainak:
 Log::emergency($message);
 Log::alert($message);
 Log::critical($message);
 Log::error($message);
 Log::warning($message);
 Log::notice($message);
 Log::info($message);
 Log::debug($message);

Tehát egy az egyben megfelel a PSR LoggerInterface-nek. Sajnos az apache loggere nem felel meg ennek az interfésznek, úgyhogy valamit tennünk kell. Ha nem hisszük el, próbáljuk ki az emergency metódust:
Route::get('/', function () {
    Log::emergency("teszt");
    return view('welcome');
});

Bizony, csúnyán elszáll a dolog:
2017-05-13T10:39:42+00:00 [main] [ERROR] [] Symfony\Component\Debug\Exception\FatalThrowableError: Call to undefined method Logger::emergency()

Mondjuk az dícséretes, hogy az errort ugyanúgy kilogoltuk :)

Mi is volt az a tervezési minta, ami két nem kompatibilis interfész áthidalására szolgált? Bizony, ez az adapter lesz, ami erősen decorator szagú is! Mivel nincs konkrét megfeleltetés, amikor swapeljük az facade mögötti objektumot, ezért létrehozunk egy adaptert, ami implementálja a LoggerInterface-t és ennek a publikus metódusait mappeljük át az apache loggerére. Most erre külön csomagot fogunk létrehozni, de az lenne a legjobb megoldás, ha már valaki létrehozott volna és azt használnánk, de abban nem lenne semmi izgalmas :)

Akkor keressünk egy megfelelő helyet erre és hozzunk létre egy szép composer.json-t:
{
    "name": "letscodehu/monolog-log4php-bridge",
    "require": {
        "apache/log4php" : "2.3",
        "psr/log" : "^1.0"
    },
    "autoload" : {
      "psr-4" : {
       "Letscodehu\\" : "src/"
      }
    },
    "authors": [
        {
            "name": "Papp Krisztián",
            "email": "fejlesztes@letscode.hu"
        }
    ],
    "require-dev": {
    "phpunit/phpunit": "^6.1"
    }
}

Szükségünk lesz az apache loggerére, valamint a PSR szabvány interfészekre, amit implementál a monolog is. Szükségünk lesz még a PHPUnitra, hogy néhány egyszerű teszttel lefedjük azt. Belőjük az autoloadert az src mappára és ezután már csak egy composer install kell és minden készen áll, hogy nekilássunk!

Hozzunk létre egy LoggerAdapter osztályt, ami egyelőre csak implementálja a LoggerInterface-t, üres metódusokkal:
namespace Letscodehu\Logger;


use Psr\Log\LoggerInterface;

/**
 * Adapter class for wrapping Apache loggers to a PSR compliant Logger.
 * @author Krisztian Papp
 */
class LoggerAdapter implements LoggerInterface {

    /**
     * @var \Logger
     */
    private $logger;

    function __construct(\Logger $logger)
    {
        $this->logger = $logger;
    }

    public function emergency($message, array $context = array())
    {
        // TODO: Implement emergency() method.

    }

    public function alert($message, array $context = array())
    {
        // TODO: Implement alert() method.

    }

    public function critical($message, array $context = array())
    {
        // TODO: Implement critical() method.

    }

    public function error($message, array $context = array())
    {
        // TODO: Implement error() method.

    }

    public function warning($message, array $context = array())
    {
        // TODO: Implement warning() method.

    }

    public function notice($message, array $context = array())
    {
        // TODO: Implement notice() method.

    }

    public function info($message, array $context = array())
    {
        // TODO: Implement info() method.

    }

    public function debug($message, array $context = array())
    {
        // TODO: Implement debug() method.

    }

    public function log($level, $message, array $context = array())
    {
        // TODO: Implement log() method.

    }
}

Akkor jöjjenek hát a tesztek, mert nem csak vaktában lövöldözni akarunk, ha már itt a legújabb PHPUnit számunkra. Hozzunk létre egy phpunit.xml-t a projekt gyökerében:
<?xml version="1.0" encoding="UTF-8"?>
<phpunit backupGlobals="false"
         backupStaticAttributes="false"
         bootstrap="vendor/autoload.php"
         colors="true"
         convertErrorsToExceptions="true"
         convertNoticesToExceptions="true"
         convertWarningsToExceptions="true"
         processIsolation="false"
         stopOnFailure="false">
    <testsuites>
        <testsuite name="Unit Tests">
            <directory suffix="Test.php">./tests</directory>
        </testsuite>
    </testsuites>
</phpunit>

Megadjuk neki a testsuite-unk helyét, ahol a Test.php végződésű fájlokat fogja nekünk felnyalni. Beállítjuk a composer autoloaderét, mint bootstrap fájl, valamint néhány alapbeállítást elvégzünk.

Ezután létrehozunk egy LoggerAdapterTest.php-t a tests mappában:
<?php


/**
 * Unit test for LoggerAdapter
 */
class LoggerAdapterTest extends \PHPUnit\Framework\TestCase {

}

Akkor most lehet elkezdeni végre kódolni :) Először is jöjjön egy törő teszt, ugye?

A teszt osztályunk setUp metódusába, ami minden teszt előtt lefut, vegyünk fel egy kódrészletet, ami az adapterünket létrehozza egy mock loggerrel:
private $mockLogger;
private $underTest;

public function setUp() {
    $this->mockLogger = $this->createMock(Logger::class);
    $this->underTest = new \Letscodehu\Logger\LoggerAdapter($this->mockLogger);
}

Ezután jöjjön egy teszt, először az info helyes működésére:
/**
 * @test
 */
public function it_should_delegate_info_call() {
    // GIVEN

    $this->mockLogger->expects($this->once())->method("info")->with("test");
    // WHEN

    $this->underTest->info("test");
    // THEN

}

A korábban átadott mock-nak most megmondjuk, hogy egyszer meg fogjuk hívni az info metódusát, mégpedig a "test" paraméterrel. Ezután meghívjuk ténylegesen és várjuk, hogy beigazolódjon a dolog. Futtassuk le a teszteket a projekt gyökerében kiadva a
vendor/phpunit/phpunit/phpunit

parancsot.
There was 1 failure:

1) LoggerAdapterTest::it_should_delegate_info
Expectation failed for method name is equal to <string:info> when invoked 1 time(s).
Method was expected to be called 1 times, actually called 0 times.

FAILURES!
Tests: 1, Assertions: 1, Failures: 1.

Természetesen failel, mivel még nincs kész az osztályunk. Zöldítsük ki a tesztet akkor!
public function info($message, array $context = array())
{
    $this->logger->info($message);
}

Ennyivel sikerül is zölddé tenni a tesztet, viszont a gond ott van, hogy van itt egy $context paraméter is. Ez a Laravel defaultok használatával egy JSON encoded stringként jelenik meg, akkor egészítsük ki a tesztünket egy új metódussal:
/**
 * @test
 */
public function it_should_delegate_info_with_json_encoded_context() {
    // GIVEN

    $this->mockLogger->expects($this->once())->method("info")->with("test {\"test\":\"test\"}");
    // WHEN

    $this->underTest->info("test", ["test" => "test"]);
    // THEN

}

Ez természetesen elszáll, úgyhogy írjuk meg a logikát hozzá:
public function info($message, array $context = array())
{
    if (empty($context)) {
        $this->logger->info($message);
    } else {
        $this->logger->info(sprintf("%s %s", $message, json_encode($context)));
    }
}

Ezzel a teszt ki is lett zöldítve. Az else ágban levő részt refaktorálhatjuk egy kicsit, mert hasonlóképpen fogunk eljárni az összes loglevel esetében a context tartalmával:
public function info($message, array $context = array())
{
    $this->logger->info($this->formatWithContext($message, $context));
}

private function formatWithContext($message, array $context)
{
    if (empty($context)) {
        $formatted = $message;
    } else {
        $formatted = sprintf("%s %s", $message, json_encode($context));
    }
    return $formatted;
}

Újrafuttatjuk a teszteket és mivel zöldek maradtak, ezért mehetünk tovább! Most nem fogok minden egyes metódusra kitérni, amiket csak így továbbadunk, hanem azokra térek ki, amik pl. nem léteznek. Ezeket az apache Logger::log metódusán át tudjuk majd elérni, aminek az első paramétere lesz a trükkös számunkra. Ahhoz, hogy új logszintet hozzunk létre, egy meglévőt kell használnunk, ugyanis egy privát konstruktorral meghiúsították azon irányú terveinket, hogy szimplán leörökítsük a LoggerLevel osztályt, ennélfogva némileg átmappeljük a dolgokat, így a monolog emergency és critical loglevelből fatal-t alkotunk, a notice-ból pedig info-t.

A kész csomag, a maga pár fájljával itt található. Akkor vissza a Laravelhez! A composer.json-ben fel kell vegyük a repositories közé a github repot, mivel packagist-re nem került ki a dolog:
"repositories" : [
  {
    "type" : "vcs",
    "url" : "https://github.com/letscodehu/monolog-log4php-bridge"
  }
],

Valamint, mivel már az adaptert akarjuk behúzni, kicserélhetjük az apache/log4php-t az adapter csomagjára a require szekcióban:
"letscodehu/monolog-log4php-bridge" : "1.0.0"

Ezután pedig updateljük a projektet:
composer update

Ezután pedig az AppServiceProviderben írjuk kicsit át a boot-ot:
$logger = \Logger::getLogger("main");
$loggerAdapter = new LoggerAdapter($logger);
Log::swap($loggerAdapter);

Ezután pedig nézzük meg újra azt az emergency-t, most ráadásként valami context-el:
Route::get('/', function () {
    Log::emergency("teszt", ["id" => "teszt"]);
    return view('welcome');
});

A logfájlokban pedig:
2017-05-13T16:54:18+00:00 [main] [FATAL] [OfrSbJozpkVLZImqNj5LSldGqNMu7n0rsfW4tyJ4] teszt {"id":"teszt"}

Tehát sikerült áthidaljuk a problémát, mondjuk nem a legszebb módszerrel. A következő cikkben megnézzük mindezt Symfony és Zend alatt is, és sorra kerül végre a Splunkos keresésre is!

Hozzászólások betöltése
2014-2017 © Letscode.hu. Minden jog fenntartva. Build verzió: 1.2.37

Mik azok a sütik?


As is common practice with almost all professional websites this site uses cookies, which are tiny files that are downloaded to your computer, to improve your experience. This page describes what information they gather, how we use it and why we sometimes need to store these cookies. We will also share how you can prevent these cookies from being stored however this may downgrade or 'break' certain elements of the sites functionality.

Áltálnos információkat nyújthat ez a Wikipedia cikk a HTTP sütikről...

Hogy használjuk a sütiket?


We use cookies for a variety of reasons detailed below. Unfortunately is most cases there are no industry standard options for disabling cookies without completely disabling the functionality and features they add to this site. It is recommended that you leave on all cookies if you are not sure whether you need them or not in case they are used to provide a service that you use.

Sütik kikapcsolása


You can prevent the setting of cookies by adjusting the settings on your browser (see your browser Help for how to do this). Be aware that disabling cookies will affect the functionality of this and many other websites that you visit. Disabling cookies will usually result in also disabling certain functionality and features of the this site. Therefore it is recommended that you do not disable cookies.

A sütik amiket mi használunk


This site offers newsletter or email subscription services and cookies may be used to remember if you are already registered and whether to show certain notifications which might only be valid to subscribed/unsubscribed users.

In order to provide you with a great experience on this site we provide the functionality to set your preferences for how this site runs when you use it. In order to remember your preferences we need to set cookies so that this information can be called whenever you interact with a page is affected by your preferences.


Harmadik féltől származó sütik


In some special cases we also use cookies provided by trusted third parties. The following section details which third party cookies you might encounter through this site.

This site uses Google Analytics which is one of the most widespread and trusted analytics solution on the web for helping us to understand how you use the site and ways that we can improve your experience. These cookies may track things such as how long you spend on the site and the pages that you visit so we can continue to produce engaging content.

For more information on Google Analytics cookies, see the official Google Analytics page.

The Google AdSense service we use to serve advertising uses a DoubleClick cookie to serve more relevant ads across the web and limit the number of times that a given ad is shown to you.

For more information on Google AdSense see the official Google AdSense privacy FAQ.

We also use social media buttons and/or plugins on this site that allow you to connect with your social network in various ways. For these to work the following social media sites including; Facebook, will set cookies through our site which may be used to enhance your profile on their site or contribute to the data they hold for various purposes outlined in their respective privacy policies.


More Information


Hopefully that has clarified things for you and as was previously mentioned if there is something that you aren't sure whether you need or not it's usually safer to leave cookies enabled in case it does interact with one of the features you use on our site. However if you are still looking for more information then you can contact us through one of our preferred contact methods.

Email: fejlesztes@letscode.hu

Bezárás