11 May

Mit tegyünk ha már elvesztünk a logfájlokban?


Ismert a mondás, hogy a fejlesztők idejük 90%-ában debuggolnak, a másik 10%-ban pedig bugokat írnak. Ez utóbbi egy lokális/remote alkalmazás esetében még a nyelvspecifikus debuggerrel megoldható, lépegethetünk soronként, megnézhetjük hogy mi is történt pontosan egy/egy request/thread mentén. Viszont amikor mindez éles, netán tesztkörnyezetbe került, akkor ez az opció elveszett, így marad az, hogy a hibakeresés szempontjából lényeges információkról logbejegyzéseket hagyunk hátra és reménykedünk hogy sosem kell belenézzünk.

Azonban a helyzet sokszor nem ilyen rózsás, hiszen képzeljünk el egy olyan alkalmazást, ami felé másodpercenként lekérések ezrei érkeznek, netán aszinkron hívásokat intézünk benne third party service-ek felé és a hiba konkrét okának visszafejtése egyre nehezebb és nehezebbé válik.

Képzeljük el a következőket egy logfájlban:

<user@email.com> logged in
Applying coupon 'please'
Uncaught exception ServiceUnavailableException. Trace: ...
<user2@email.com> logged in
Payment service is down
Applying coupon 'please'
Coupon apply error - Already applied.

A fenti logbejegyzések, habár önmagukban megállják a helyüket, ha hibát keresünk, akkor bizony keveredhetnek a dolgok. Kapunk egy olyan hibaticketet például, hogy a felhasználónk, mikor kupont próbált használni a vásárláskor, az nem engedte neki, hanem hibát dobott a rendszer. Megkapjuk a tickettel a felhasználó e-mail címét, ami user@email.com. A fentiek alapján még az is lehet, hogy mindkét kupont ő próbálta használni, de az is lehet, hogy csak egyszer próbálta, viszont az is előfordulhat, hogy a hiba nem is nála fordult elő, hanem egy olyan ágba futott a kód, amiről eddig nem tudtunk. Ha dátummal prefixáljuk a dolgot, az talán segíthet, de még az sem tudja feltétlenül megoldani a dolgot, így valami más után kell nézzünk.

A fogalom, amit mi keresünk az ún. mapped diagnostic context, röviden MDC lesz. Ez nem jelent mást, mint annyit, hogy a debuggolás szempontjából fontos információkat hozzácsapjuk a logbejegyzésekhez, ezáltal össze tudjuk kapcsolni azokat, az egyenként értelmetlen sorok értelmet nyernek. Ezt úgy fogjuk megcsinálni, hogy az egyes requestek bejövetelekor, még mielőtt bármit is kezdenénk a lekéréssel, a tudtára hozzuk ezeket a loggernek és utána minden logbejegyzésben ott lesz mindez.

Mi lehet lényeges információ ilyenkor?
  • session ID

  • user ID / email cím

  • ha load balancer mögött vagyunk, akkor az instance ID-ja

  • és még sok más, ami domaintől függően segíthet


Na és hogy tudjuk ezeket ügyesen használni?

A józanul íródott logger librarykben már jelen vannak olyan helperek, amik segítenek nekünk abban, hogy requestenként beállítsuk a megadott MDC változókat, de a sokszor használt monolog-ban ez nem így van, így aki szeretne ilyesmit, annak egy kis mágiához kell folyamodni innen. Mi viszont a Javából már jól ismert log4j PHP-s párját, a log4php-t fogjuk használni most. Húzzuk is le a composer segítségével!
composer require apache/log4php:^2.3

Vagy kézzel adjuk hozzá azt a JSON-höz:
"require": {
    "apache/log4php" : "2.3"
},

Ezután a rendelkezésünkre is áll minden függőség, amire szükségünk van.

Nem fogunk most keretrendszer specifikusan belemenni a dolgokba, legyen elég annyi, hogy lévén itt nem kell attól félnünk, hogy két requestet szolgálna ki egy logger, ezért annyi a dolgunk, hogy azokat az információkat, amik segítségünkre lehetnek a hibakeresésben, minél előbb beállítjuk. Ez pl. egy Laravel esetében before middleware-be kerülne, hogy még a controller dolgai előtt beállítsuk az értéket, hogy utána már a logolás a beállított értékkel történjen. A kód, amit mi használni fogunk, nagyon egyszerű, kb. egy szimpla index.php:
<?php

require_once "vendor/autoload.php";

Logger::configure("logger.php");

LoggerMDC::put("guid", "dc7bd828-6bdb-4075-85dd-f1e8de037f8e");
$logger = Logger::getLogger("main");

$logger->info("This is what happens when you got MDC");

Semmi nem történt, csak behúztuk a composer autoloaderét, utána felkonfiguráltuk a Loggert. Ezután beállítottunk egy MDC-t, mégpedig guid névvel. Tegyük fel, hogy ilyen GUID azonosítókkal látjuk el az egyes usereket. Emellé bekerülhet egy session id is, amivel már azt is tudjuk figyelni, hogy az adott user esetleg két böngészővel betyárkodik egyszerre, de most csak röviden.  Ezután kikérjük a loggert egy factory-ból, aminek átadjuk a Loggerünk nevét. Ezt általában az adott osztályra szokták szabni, tehát
$logger = Logger::getLogger(__CLASS__);

a megfelelő módja, ha osztályokban használjuk. A logger.php tartalma pedig:
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' => 'file.log',
                'append' => true
            ),
        ),
    ),
    'rootLogger' => array(
        'appenders' => array('default'),
    )
);

Az apache loggere úgy működik, hogy több úgynevezett logger appender-t is megadhatunk, ezáltal több dolgot többféleképpen is tudunk logolni. Mi itt most csak egy ilyen appendert akarunk, ami fájlba fog logolni. Ezután megadjuk neki, hogy milyen sémát kövessenek az egyes logbejegyzések. Nekünk most egy dátum, utána a logger neve (__CLASS__ esetén az osztály neve), utána a log szintje, ezután pedig a guid MDC értéke és legvégül az üzenet, amit logolunk. Egy logbejegyzés a fenti kódot lefuttatva az alábbi módon fest:
2017-05-06T21:12:13+02:00 [main] [INFO ] [dc7bd828-6bdb-4075-85dd-f1e8de037f8e] This is what happens when you got MDC

Az összes ezt követő logbejegyzés tartalmazni fogja ezt a bejegyzést, egészen az adott HTTP request végéig, hacsak explicit, ki nem vesszük azt a
LoggerMDC::remove("guid");

A következő részben megnézzük, hogy tudjuk mindezen működést alkalmazni Symfony 3/Laravel 5 alatt, valamint megnézzük a kapott logokban való keresgélést Splunk segítségével! Sorra veszünk pár trükköt is, hogy pl. a production/staging environmentben ne hányjuk tele terabájtokkal a logokat, hanem mindezt adott sessionhöz kössük és még egyéb finomságokat!

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