Django naplózás, a helyes út

A jó naplózás kritikus fontosságú a hibakeresés és a hibaelhárítás szempontjából. Nemcsak a helyi fejlesztés során hasznos, hanem a termelésben is nélkülözhetetlen. Egy probléma naplóinak áttekintésekor ritkán halljuk, hogy valaki azt mondja: “Túl sok naplózás van az alkalmazásunkban.”, de gyakran halljuk a fordítottját. Szóval, ezt szem előtt tartva kezdjünk bele.

Egy gyorstalpaló tanfolyam a Python loggerekből

Minden fájl tetején valami ilyesminek kell lennie:

import logginglogger = logging.getLogger(__name__)

__name__ kiértékeli a modul pontozott Python-útvonalát, pl. myproject/myapp/views.py a myproject.myapp.views-t fogja használni. Most már használhatjuk ezt a naplózót az egész fájlban így:

# A simple string logged at the "warning" levellogger.warning("Your log message is here")# A string with a variable at the "info" levellogger.info("The value of var is %s", var)# Logging the traceback for a caught exceptiontry: function_that_might_raise_index_error()except IndexError: # equivalent to logger.error(msg, exc_info=True) logger.exception("Something bad happened")

Megjegyzés: A Python naplózói kezelik a változók beillesztését a naplóüzenetbe, ha azokat argumentumként adjuk át a naplózási függvényben. Ha a naplónak nincs szüksége a kimenetre, a változó behelyettesítése soha nem fog megtörténni, segít elkerülni egy kis teljesítménycsökkenést egy olyan naplóhoz, amelyet soha nem fogunk használni.

Bőkezűen fűszerezd a kódodat ezekkel a naplózási utasításokkal. Íme az általam használt hüvelykujjszabály a naplózási szintekre:

  • debug: A rendszeres működéshez nem szükséges, de a fejlesztés során hasznos információ.
  • info: A rendszeres működés során hasznos információ.
  • warning: Olyan információ, amely problémás lehet, de nem sürgős.
  • error: Olyan információ, amely fontos és valószínűleg azonnali figyelmet igényel.
  • critical: A gyakorlatban nem használom, de ha a error-nál magasabbra van szükséged, akkor itt van

Hová kell naplózni

Az alkalmazásodnak nem kell foglalkoznia azzal, hogy hová kerülnek a naplói. Ehelyett mindent a konzolra (stdout/stderr) kell naplóznia, és hagynia kell, hogy a szerver döntse el, hogy onnantól kezdve mit csináljon vele. Általában ez egy dedikált (és naplózott) fájlba kerül, a Systemd napló vagy a Docker rögzíti, elküldi egy különálló szolgáltatásnak, például az ElasticSearch-nek, vagy ezek valamilyen kombinációja. A naplótárolás a telepítéssel kapcsolatos, nem az alkalmazással.

Az egyetlen dolog, amivel az alkalmazásnak foglalkoznia kell, az a naplók formátuma. Általában ez csak egy sztring a vonatkozó adatokkal, de ha a kiszolgálója már időbélyeget ad a naplóhoz, akkor valószínűleg ki akarja zárni a saját formatter. Hasonlóképpen, ha a naplóaggregátorod képes JSON-t elfogadni, egy olyan formázó, mint a python-json-logger megfelelőbb lehet.

A naplózó konfigurálása

A naplózókba való írás Pythonban egyszerű. Konfigurálni őket, hogy a megfelelő helyre kerüljenek, nagyobb kihívás, mint gondolnád. Kezdem a Django alapértelmezett naplózásának megkerülésével, ahogy azt az előző bejegyzésemben leírtam. Ezzel egy üres lapot kapunk, amivel dolgozhatunk.

A Sentry beállítása

A hibajelentő szolgáltatások kritikusak minden nem triviális webhely számára. Alapértelmezés szerint ezek elkapják a nem fogott kivételeket, értesítik a problémáról (incidensenként csak egyszer), és egy szép felületet biztosítanak az alkalmazás állapotának megtekintéséhez, amikor a kivétel bekövetkezett. Az én kedvenc szolgáltatásom erre a célra a Sentry.

A Sentry-t egy lépéssel tovább vihetjük azzal, hogy minden warning vagy magasabb szintű naplóüzenetet is elküldünk a szolgáltatásnak. Ezek egyébként elvesznének a naplófájlok tengerében, amelyeket a gyakorlatban ritkán néznek át. Ehhez hozzáadunk egy “root” loggert, amely gyűjtőhelyként szolgál minden olyan naplóüzenet számára, amelyet bármelyik Python modul küld. Ez valahogy így néz ki a Django beállításaiban,

import logging.configLOGGING_CONFIG = Nonelogging.config.dictConfig({ 'version': 1, 'disable_existing_loggers': False, 'formatters': { 'console': { # exact format is not important, this is the minimum information 'format': '%(asctime)s %(name)-12s %(levelname)-8s %(message)s', }, }, 'handlers': { 'console': { 'class': 'logging.StreamHandler', 'formatter': 'console', }, # Add Handler for Sentry for `warning` and above 'sentry': { 'level': 'WARNING', 'class': 'raven.contrib.django.raven_compat.handlers.SentryHandler', }, }, 'loggers': { # root logger '': { 'level': 'WARNING', 'handlers': , }, },})

Logging From Your Application

Míg lehet, hogy csak a harmadik féltől származó függőségek figyelmeztetéseiről és hibáiról szeretnénk tudni, általában sokkal mélyebb betekintést szeretnénk az alkalmazásunk kódjába. Ideális esetben az összes kódod egyetlen névtér alatt él, így egyetlen loggers kiegészítéssel rögzíthető. Tegyük fel, hogy a projekted a myproject névteret használja, a fenti kódra építve ezt adnád hozzá:

logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': 'INFO', 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, },})

De mi van, ha a debug naplózással mélyebben szeretnél vizsgálni valamit az alkalmazásodban? Az, hogy új kódot kell commitolni és telepíteni, túlzásnak tűnik. Ez egy nagyszerű felhasználási eset a környezeti változók számára. Módosíthatjuk az előző stanzát, hogy így nézzen ki:

import osLOGLEVEL = os.environ.get('LOGLEVEL', 'info').upper()logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': LOGLEVEL, 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, },})

Most az alkalmazásunk naplózása alapértelmezetten info lesz, de könnyen növelhető ideiglenesen a LOGLEVEL=debug környezeti változó beállításával. Alternatívaként, ha a naplótárolás nem jelent problémát, fontoljuk meg, hogy mindig a debug szinten naplózunk. Ezeket elég könnyű kiszűrni egy egyszerű grep segítségével vagy a naplóadatokat megjelenítő eszközödön keresztül, például a Kibana segítségével.

A zaj kivágása

Ha már beállítottad és működtetted a naplózást, előfordulhat, hogy néhány modul olyan információkat naplóz, amelyek nem igazán érdekelnek, és csak arra szolgálnak, hogy extra zajt okozzanak (rád nézek newrelic). Ezekhez a modulokhoz hozzáadhatunk egy másik naplózót, hogy kikapcsoljuk őket. Az első lehetőség, hogy a konzolra naplózzuk őket, de elkerüljük a root loggerbe való átvitelüket, ami a Sentrybe küldené őket:

logging.config.dictConfig({ # ... 'loggers': { '': { 'level': 'WARNING', 'handlers': , }, 'myproject': { 'level': LOGLEVEL, 'handlers': , # required to avoid double logging with root logger 'propagate': False, }, # Don't send this module's logs to Sentry 'noisy_module': { 'level':'ERROR', 'handlers': , 'propagate': False, }, },})

Ha úgy találjuk, hogy túl zajosak, még a konzol számára is, akkor teljesen elhagyhatjuk őket:

logging.config.dictConfig({ # ... 'loggers': { # ... # Don't log this module at all 'noisy_module': { 'level': 'NOTSET', 'propagate': False, }, },})

Local Request Logging

A Django alapértelmezett konfigurációjának egyik szépsége a kérések naplózása a runserverrel. A Django konfigurációjának felülírásával ezt elveszítjük, de elég könnyű visszaadni:

from django.utils.log import DEFAULT_LOGGINGlogging.config.dictConfig({ # ... 'formatters': { # ... 'django.server': DEFAULT_LOGGING, }, 'handlers': { # ... 'django.server': DEFAULT_LOGGING, }, 'loggers': { # ... 'django.server': DEFAULT_LOGGING, },})

Leave a Reply