nginx: Logovanje

Ciljevi lekcije

Nakon ove lekcije trebalo bi da:

  • napišeš format loga koji sadrži ono što ti stvarno treba pri dijagnostici
  • razumeš nivoe grešaka i šta se pojavljuje na kojem
  • podesiš rotaciju i znaš zašto nginx mora da bude obavešten o njoj
  • izvučeš korisne podatke iz loga bez posebnih alata
  • anonimizuješ IP adrese kada to treba

1. Dva loga

Access log beleži svaki zahtev. Piše se nakon što je odgovor poslat.

Error log beleži probleme — od kritičnih grešaka do informativnih poruka, zavisno od podešenog nivoa. Kada nešto ne radi, ovde gledaš prvo.

Podrazumevane putanje na Ubuntu-u su /var/log/nginx/access.log i /var/log/nginx/error.log. U lekciji 4 smo ih razdvojili po sajtovima — to je praksa koje se drži.

2. Formati access loga

Podrazumevani format zove se combined:

log_format combined '$remote_addr - $remote_user [$time_local] '
                    '"$request" $status $body_bytes_sent '
                    '"$http_referer" "$http_user_agent"';

Za produkciju je nedovoljan. Nedostaje mu ono što najviše koristiš pri dijagnostici — vreme obrade, ponašanje backend-a, status keša.

Format za rad sa proxy-jem

log_format prosiren
    '$remote_addr - $remote_user [$time_local] '
    '"$request" $status $body_bytes_sent '
    '"$http_referer" "$http_user_agent" '
    'rt=$request_time urt=$upstream_response_time '
    'us=$upstream_status ua=$upstream_addr '
    'cs=$upstream_cache_status host=$host';

access_log /var/log/nginx/access.log prosiren;

Šta je vredno u tim dodacima:

Promenljiva Zašto je važna
$request_time ukupno vreme, od prvog bajta zahteva do poslednjeg bajta odgovora
$upstream_response_time koliko je trajao backend
$upstream_status šta je backend vratio pre nego što je nginx to eventualno promenio
$upstream_addr koji server iz grupe je obradio zahtev
$upstream_cache_status HIT/MISS/STALE
$host koji domen, kad na jednom serveru ima više sajtova

Razlika $request_time i $upstream_response_time je dijagnostički najkorisniji podatak koji imaš. Ako je backend vratio odgovor za 20 ms a ukupno vreme je 3 sekunde, aplikacija nije kriva — problem je u mreži ka klijentu ili u sporom slanju tela zahteva.

JSON format

Ako logove šalješ u sistem za centralizovanu obradu, JSON štedi posao parsiranja:

log_format json escape=json
'{'
  '"time":"$time_iso8601",'
  '"remote_addr":"$remote_addr",'
  '"method":"$request_method",'
  '"uri":"$request_uri",'
  '"status":$status,'
  '"bytes":$body_bytes_sent,'
  '"request_time":$request_time,'
  '"upstream_time":"$upstream_response_time",'
  '"cache":"$upstream_cache_status",'
  '"host":"$host",'
  '"referer":"$http_referer",'
  '"user_agent":"$http_user_agent",'
  '"request_id":"$request_id"'
'}';

Parametar escape=json je obavezan — bez njega navodnik u User-Agent zaglavlju razbija zapis i celu naredbu za parsiranje.

$request_id — povezivanje sa aplikacijom

nginx za svaki zahtev generiše jedinstveni identifikator. Prosledi ga aplikaciji:

proxy_set_header X-Request-ID $request_id;

Ako ga aplikacija upiše u svoje logove, možeš da pratiš jedan zahtev kroz oba sistema. Kada korisnik prijavi problem, tražiš jedan niz umesto da poredis vremenske oznake.

3. Šta ne logovati

Access log troši disk i I/O. Neke stvari ne vrede zapisivanja:

location = /health {
    access_log off;
    return 200 "ok\n";
}

location ~* \.(css|js|jpg|png|woff2)$ {
    expires 30d;
    access_log off;
}

location = /favicon.ico {
    access_log off;
    log_not_found off;
}

log_not_found off sprečava upisivanje 404 grešaka u error log. Bez toga, svaki bot koji traži /wp-admin/ puni ti error log šumom.

Uslovno logovanje

Zapisuj samo ono što nije prošlo kako treba:

map $status $zabelezi {
    ~^[23]  0;
    default 1;
}

access_log /var/log/nginx/greske.log prosiren if=$zabelezi;

Isto radi i za spore zahteve:

map $request_time $sporo {
    default 0;
}

Ovo drugo traži malo više posla jer map ne poredi brojeve, ali se rešava kroz regularni izraz nad vrednošću.

Baferisanje

Na sajtu sa velikim saobraćajem, upis u log po zahtevu je merljiv trošak:

access_log /var/log/nginx/access.log prosiren buffer=32k flush=5s;

nginx sakuplja zapise u memoriji i upisuje ih kada se bafer napuni ili prođe pet sekundi. Cena je što se poslednjih nekoliko sekundi može izgubiti ako proces padne — za access log je to prihvatljivo.

4. Error log i nivoi

error_log /var/log/nginx/error.log warn;

Nivoi, od najopširnijeg ka najužem:

Nivo Šta obuhvata
debug sve, uključujući unutrašnje odluke; traži build sa --with-debug
info informativne poruke
notice značajni događaji
warn upozorenja koja ne prekidaju rad
error greške u obradi zahteva — podrazumevani
crit ozbiljni problemi
alert zahteva hitnu reakciju
emerg server ne može da radi

Navedeni nivo znači „on i sve iznad njega". warn obuhvata i error, crit i dalje.

Za produkciju je warn dobar izbor — hvata i stvari koje najavljuju probleme, a ne preplavljuje.

Debug log

Kada moraš da vidiš šta nginx zapravo radi:

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

events {
    debug_connection 192.0.2.55;
}

debug_connection ograničava opširno logovanje na jednu IP adresu ili opseg, pa možeš da debuguješ na živom serveru bez da ga zatrpaš. Tu ćeš videti i izbor location bloka iz lekcije 5, red po red.

Isključi kada završiš. Debug log ume da naraste gigabajtima na sat.

Poruke koje ćeš najčešće sretati

Poruka Značenje
connect() failed (111: Connection refused) backend ne radi
upstream timed out (110: Connection timed out) prekoračen proxy_read_timeout
upstream prematurely closed connection backend je pao usred obrade
Permission denied dozvole nad fajlom, direktorijumom ili socket-om
directory index of "..." is forbidden nema index fajla, autoindex isključen
client intended to send too large body client_max_body_size
upstream sent too big header proxy_buffer_size
rewrite or internal redirection cycle petlja u try_files ili rewrite
worker_connections are not enough dostignut limit; vidi lekciju o tuningu
SSL_do_handshake() failed problem u TLS rukovanju, često stari klijent

5. Rotacija

Bez rotacije, log fajl raste dok ne popuni disk. Ubuntu paket instalira konfiguraciju u /etc/logrotate.d/nginx:

/var/log/nginx/*.log {
        daily
        missingok
        rotate 14
        compress
        delaycompress
        notifempty
        create 0640 www-data adm
        sharedscripts
        prerotate
                if [ -d /etc/logrotate.d/httpd-prerotate ]; then \
                        run-parts /etc/logrotate.d/httpd-prerotate; \
                fi \
        endscript
        postrotate
                if [ -f /run/nginx.pid ]; then
                        kill -USR1 `cat /run/nginx.pid`
                fi
        endscript
}

Onaj kill -USR1 je ključni deo i vredi razumeti zašto.

Kada logrotate preimenuje access.log u access.log.1, nginx i dalje drži otvoren deskriptor ka istom fajlu pod novim imenom i nastavlja da piše u njega. Novi access.log ostaje prazan zauvek. Signal USR1 govori nginx-u da zatvori i ponovo otvori sve log fajlove — tek tada počinje da piše u novi.

Isto možeš i ručno:

sudo nginx -s reopen

Ako ikada napišeš sopstvenu skriptu za rotaciju, ne zaboravi ovaj korak. To je greška koja se otkrije tek kad ti zatreba log od pre nedelju dana.

Prilagođavanje

Za sajtove sa velikim saobraćajem, dnevna rotacija može biti nedovoljna:

/var/log/nginx/*.log {
        size 100M
        rotate 30
        compress
        delaycompress
        ...
}

Testiraj bez stvarnog izvršavanja:

sudo logrotate -d /etc/logrotate.d/nginx

Prisilno pokretanje:

sudo logrotate -f /etc/logrotate.d/nginx

6. Anonimizacija IP adresa

Ako te obavezuje GDPR ili slična regulativa, IP adrese u logu su lični podaci. Skraćivanje poslednjeg okteta zadržava korisnost za analitiku, a uklanja mogućnost identifikacije:

map $remote_addr $ip_anon {
    ~(?P<ipv4>\d+\.\d+\.\d+)\.\d+     $ipv4.0;
    ~(?P<ipv6>[^:]+:[^:]+):           $ipv6::;
    default                            0.0.0.0;
}

log_format anon '$ip_anon - [$time_local] "$request" $status '
                '$body_bytes_sent rt=$request_time';

access_log /var/log/nginx/access.log anon;

Imaj u vidu da ovo otežava dijagnostiku napada i rad fail2ban-a. Uobičajen kompromis je puna adresa u error logu uz kratak rok čuvanja, a anonimizovana u access logu.

Konsultuj se sa nekim ko poznaje pravni okvir tvoje organizacije — ovo je tehnički deo, ne pravni savet.

7. Analiza bez posebnih alata

Nekoliko komandi koje pokrivaju većinu potreba. Podrazumevaju combined format; prilagodi brojeve kolona ako koristiš svoj.

Najčešće IP adrese:

awk '{print $1}' /var/log/nginx/access.log | sort | uniq -c | sort -rn | head -20

Raspodela statusnih kodova:

awk '{print $9}' /var/log/nginx/access.log | sort | uniq -c | sort -rn

Najtraženije putanje:

awk '{print $7}' /var/log/nginx/access.log | sort | uniq -c | sort -rn | head -20

Sve greške 5xx sa vremenom:

awk '$9 ~ /^5/ {print $4, $7, $9}' /var/log/nginx/access.log | tail -50

Najsporiji zahtevi (uz prosiren format, gde je rt= pretposlednje polje):

grep -oP 'rt=\K[0-9.]+.*' /var/log/nginx/access.log | sort -rn | head -20

Saobraćaj po satu:

awk '{print substr($4, 2, 14)}' /var/log/nginx/access.log | uniq -c

Ko generiše 404 greške:

awk '$9 == 404 {print $7}' /var/log/nginx/access.log | sort | uniq -c | sort -rn | head -20

Poslednja komanda često otkriva pokvarene linkove na sopstvenom sajtu, a ne samo botove.

8. GoAccess

Za pregledan izveštaj bez postavljanja celog sistema za obradu logova:

sudo apt install goaccess

Izveštaj u terminalu:

goaccess /var/log/nginx/access.log --log-format=COMBINED

HTML izveštaj:

goaccess /var/log/nginx/access.log --log-format=COMBINED -o /var/www/izvestaj.html

Uživo, sa osvežavanjem:

goaccess /var/log/nginx/access.log --log-format=COMBINED \
  -o /var/www/izvestaj.html --real-time-html

Ako koristiš sopstveni format, moraš ga opisati GoAccess-u kroz --log-format, --date-format i --time-format. Za JSON logove postoji poseban režim.

Zaštiti izveštaj ako ga serviraš preko web-a — sadrži IP adrese posetilaca i strukturu sajta. Kontrola pristupa je tema sledeće lekcije.

9. Slanje logova van servera

Za više servera, čuvanje logova lokalno prestaje da bude praktično. nginx može da piše direktno u syslog:

access_log syslog:server=10.0.0.50:514,tag=nginx,severity=info prosiren;
error_log  syslog:server=10.0.0.50:514,tag=nginx_error warn;

Odatle ih preuzima rsyslog, Loki, Elasticsearch ili šta već koristiš.

Prostija varijanta je ostaviti lokalno pisanje i dodati agenta (Promtail, Filebeat, Vector) koji prati fajl i prosleđuje ga. Prednost je što lokalni log ostaje dostupan i kada je centralni sistem nedostupan.


Praktična vežba

1. Napravi prošireni format iz teksta i primeni ga na jedan sajt. Pošalji nekoliko zahteva i pogledaj razliku u odnosu na combined.

2. Uoči razliku između $request_time i $upstream_response_time. Napravi backend koji namerno kasni:

setTimeout(() => res.end('gotovo\n'), 2000);

Pošalji zahtev i pogledaj poslednji red loga — obe vrednosti biće oko 2 sekunde. Zatim simuliraj sporog klijenta:

curl --limit-rate 1k -H "Host: proxy.local" http://localhost/veliki.html

Sada je rt mnogo veći od urt. To je situacija u kojoj aplikacija nije kriva.

3. Podesi $request_id i proslediti ga backend-u. Ispiši ga u odgovoru aplikacije i pronađi isti niz u nginx logu.

4. Demonstriraj zašto je USR1 potreban:

sudo mv /var/log/nginx/access.log /var/log/nginx/access.log.test
curl -s -H "Host: test.local" http://localhost/ > /dev/null
ls -l /var/log/nginx/access.log*        # novi fajl ne postoji
tail -1 /var/log/nginx/access.log.test  # zapis je otišao ovde

sudo nginx -s reopen
curl -s -H "Host: test.local" http://localhost/ > /dev/null
ls -l /var/log/nginx/access.log         # sada postoji

5. Testiraj logrotate bez izvršavanja:

sudo logrotate -d /etc/logrotate.d/nginx 2>&1 | head -30

6. Isključi logovanje statike i health provere, pošalji dvadesetak zahteva za slike i uveri se da se log nije popunio.

7. Prođi kroz sve awk komande iz odeljka 7 nad svojim logom. Za svaku, objasni sebi šta konkretno vidiš.

8. Uključi debug za jednu IP adresu, pošalji jedan zahtev i pronađi u debug logu redove koji počinju sa test location:. Uporedi sa onim što si naučio u lekciji 5. Zatim isključi debug.

9. Napravi GoAccess izveštaj i pogledaj ga u browseru.


Rezime

  • combined format je nedovoljan za produkciju; dodaj $request_time, $upstream_response_time, $upstream_status i $upstream_cache_status.
  • Razlika između $request_time i $upstream_response_time odmah razdvaja sporu aplikaciju od spore veze ka klijentu.
  • Za JSON format je escape=json obavezan.
  • $request_id prosleđen aplikaciji povezuje nginx i aplikacione logove.
  • access_log off za statiku i health provere; log_not_found off za favicon.ico i slično.
  • Nivo warn u error logu je dobar produkcijski izbor.
  • debug_connection omogućava debug logovanje za jednu IP adresu na živom serveru.
  • Rotacija bez USR1 signala znači da nginx nastavi da piše u preimenovan fajl, a novi ostaje prazan.
  • Anonimizacija IP adresa se radi kroz map, uz svest da otežava dijagnostiku i rad fail2ban-a.
  • Za većinu analiza dovoljni su awk, sort i uniq; GoAccess daje pregledan izveštaj bez postavljanja infrastrukture.

Pitanja za proveru

  1. $request_time je 5 sekundi, $upstream_response_time je 0.05 sekundi. Šta zaključuješ?
  2. Zašto je escape=json obavezan u JSON formatu loga?
  3. Logrotate je odradio posao, ali novi access.log ostaje prazan. Šta nedostaje?
  4. Čemu služi log_not_found off i u koji log utiče?
  5. Kako uključuješ debug logovanje na produkcijskom serveru bez da ga zatrpaš?
  6. Šta znači error_log ... warn; — koje poruke se zapisuju?
  7. Kako povezuješ jedan zahtev u nginx logu sa zapisom u logu aplikacije?

Sledeća lekcija: kontrola pristupa i zaštita — allow/deny, basic auth, ograničavanje brzine zahteva i fail2ban.

Comments

Popular posts from this blog

Početak u Linuxu — šta je i zašto se uči

Konverzija tipova podataka u Pythonu

groupadd