ELK, diétára fogva

CC0 image by evondue

Az előző bejegyzésben egyedi megoldásokkal kísérletezgettünk, most pedig megnézzük a logolás világának iparági sztenderdjét, az Elastic Stack-et... egy kis csavarral.

Az Elasticsearch az a szervereknek, mint a Chrome az asztali gépeknek. Végtelen mennyiségű memóriát képes felemészteni. Vannak környezetek, ahol meg is kapja ezt, de mi továbbra is maradunk a hobbi felhasználás szintjén és megpróbáljuk felvarázsolni a legkisebb DigitalOcean-ös droplet-re. Ez jelenleg egy 1 GB memóriával és 1 vCPU-val rendelkező instance-t jelent.

Előkészületek

Fogjunk egy frissen felhúzott Ubuntu 16.04-et. Ez alapjáraton úgy 60 MB memóriát használ, de nyerhetünk még egy kicsit, ha megszabadulunk a snapd és a do-agent csomagtól (ha bekapcsoltuk a monitoringot a droplet létrehozása során).

$ apt remove snapd do-agent

Így már egy kicsit kellemesebb 45 MB környékén járunk.

Jöhet az Elasticsearch PGP kulcsának és APT repository-jának importálása:

$ wget -qO - https://artifacts.elastic.co/GPG-KEY-elasticsearch | apt-key add -
$ echo "deb https://artifacts.elastic.co/packages/6.x/apt stable main" | tee -a /etc/apt/sources.list.d/elastic-6.x.list
$ apt update

Valamint a JRE telepítése:

$ apt install default-jre

Ezzel az előkészületek végére értünk, jöhet a lényeg.

Kibana

A Kibana-val kezdjük a sort, mert annak a memória felhasználását nem nagyon tudjuk befolyásolni, úgyhogy kénytelenek leszünk az Elasticsearch-öt a fennmaradó mennyiséghez igazítani.

$ apt install kibana nginx
$ service kibana start

A Kibana-t az alapértelmezett beállításokkal fogjuk használni, az nginx-nek viszont meg kell mondani, hogy proxy-zzon.

/etc/nginx/sites-enabled/default
location / {
    proxy_pass              http://127.0.0.1:5601;
    proxy_set_header        Host $host;
    proxy_set_header        Referer "";
    proxy_set_header        X-Real-IP $remote_addr;
    proxy_set_header        X-Forwarded-For $proxy_add_x_forwarded_for;
}

A memória használatunk itt már 170 MB környékén jár.

Elasticsearch

El is érkeztünk a lényeghez. Nem meglepő, hogy egy kis telepítéssel fogunk kezdeni.

$ apt install elasticsearch

Az elindítással itt még nem is érdemes próbálkozni, mert az alapértelmezett beállításokkal több memória kellene neki, mint amennyi a gépben összesen van, úgyhogy egy kis config módosítással kezdünk:

/etc/elasticsearch/jvm.options
-Xms512m
-Xmx512m

És ezek után már el is tudjuk indítani:

$ service elasticsearch start

Elértük a 850 MB-ot, maradt még egy kis feleslegünk is, amit használhat a rendszer. Minden szépnek és jónak tűnik, de próbáljunk csak meg mondjuk egy apt update-et futtatni és máris érdekes és változatos hibaüzeneteket kaphatunk:

Unknown error executing apt-key

Could not execute 'apt-key' to verify signature (is gnupg installed?)

Couldn't spawn new process

FATAL -> Failed to fork.

Cannot allocate memory

Szerencsére az utolsó sor már elég világos. Sejteni lehet, hogy mi a probléma. Irány a jvm.options! Egy 448-as vagy 384-es értékkel érdemes megpróbálkozni. Vagy akár le is kapcsolhatjuk a Kibana-t arra az időre, amíg valami mást is szeretnénk csinálni a szerveren.

Logstash

A Logstash egy Elasticsearch-höz hasonló Java-s memóriavámpír. Érezhető, hogy nem igazán van már neki hely. Ezt egy ügyes kis trükkel fogjuk megoldani: meg se próbáljuk feltelepíteni. Helyette megpróbáljuk elérni azt, hogy ne is legyen rá szükségünk.

Az rsyslog például elég okos és képes egyből Elasticsearch-be küldeni a logokat.

$ apt install rsyslog-elasticsearch

A JSON template definíciója az előző bejegyzésből már ismerős lehet.

/etc/rsyslog.d/10-elastic.conf
template(name="syslog-json" type="list") {
  constant(value="{")

  constant(value="\"timestamp\":\"")
  property(name="timereported" dateFormat="rfc3339" format="json")

  constant(value="\",\"host\":\"")
  property(name="hostname" format="json")

  constant(value="\",\"tag\":\"")
  property(name="programname" format="json")

  constant(value="\",\"facility\":\"")
  property(name="syslogfacility-text" format="json")

  constant(value="\",\"severity\":\"")
  property(name="syslogseverity-text" format="json")

  constant(value="\",\"message\":\"")
  property(name="msg" format="json")

  constant(value="\"}")
}

module(load="omelasticsearch")
action(type="omelasticsearch" template="syslog-json")

Szinte már túl egyszerűnek is tűnik. Ezen a ponton egy jó órát töltöttem el annak a kiderítésével, hogy miért nem érkeznek meg a logok. Elég irónikus, hogy az rsyslog nem nagyon logol, így az ő oldalán nem sok minden derült ki és az Elasticsearch se sokat segített.

A végén már odáig fajult a dolog, hogy tcpdump-pal néztem a kettő közötti forgalmat és így derült ki, hogy az rsyslog text/json content type-ot küld, a 6-os Elasticsearch-ben pedig szigor van és csak az application/json-t fogadja el.

Az Ubuntu 16.04-ben 8.16.0-s rsyslog van, ezt a problémát pedig a 8.30.0-ban javították, úgyhogy szereznünk kell egy frissebb verziót:

$ add-apt-repository ppa:adiscon/v8-stable
$ apt update
$ apt upgrade

És már jönnek is a logok. Az rögtön látszódik, hogy a Kibana már JSON formátumba logol, amit kijavíthatunk egy hasonló megoldással, mint amit az előző bejegyzésben is használtunk:

/etc/rsyslog.d/10-elastic.conf
template(name="json-msg" type="list") {
  property(name="msg")
}

if $programname == "kibana" then {
  action(type="omelasticsearch" template="json-msg" searchIndex="kibana")
  stop
}

Az nginx-et is rábírhatjuk, hogy JSON logokat adjon ki magából, de nem lesz vele olyan egyszerű dolgunk, ha ezredmásodperc pontosságú logokat szeretnénk és továbbra sem akarunk egy log feldolgozó/transzformáló réteget.

A log formátum megadásánál használható $msec (unix idő másodpercekben, ezredmásodperc pontossággal) nem támogatja dátumformátumként az Elasticsearch. Van sima unix idő másodpercben és unix idő ezredmásodpercben, de mindkettő egész számként. Szerencsére a Lua mindent képes megoldani.

/etc/nginx/sites-enabled/default
log_format json escape=json '{"timestamp": $epoch_millis, '
  '"network":{'
  '"client_ip": "$remote_addr", '
  '"bytes_write": $body_bytes_sent}, '
  '"http":{'
  '"ident": "$host", '
  '"response_time": $request_time, '
  '"status_code": $status, '
  '"request": "$request_uri", '
  '"verb": "$request_method", '
  '"referer": "$http_referer", '
  '"useragent": "$http_user_agent"}, '
  '"message": "$request"}';

server {
    # ...

    set_by_lua_block $epoch_millis { return ngx.var.msec * 1000 }
    access_log syslog:server=unix:/dev/log,nohostname json;
}

A set_by_lua_block használatához szükségünk lesz az nginx-extras csomagra. És ha még nem lenne elég a menet közben felmerülő problémákból, az Ubuntu 16.04-ben lévő nginx verzió nem tudja a log_format-nál az escape paramétert, így abból is kell egy frissebb:

$ add-apt-repository ppa:nginx/stable
$ apt update
$ apt upgrade

Tovább is van, mondjam még? Ha ezt így megpróbáljuk beküldeni, akkor a timestamp mezőnk sima long típusú lesz, nem date. Ez aztán szomorú Kibana-hoz vezet, ami végső soron szomorú felhasználókat fog eredményezni. Kell egy kis előkészület Elasticsearch-ben, hogy mindenki boldog legyen:

$ curl -d@mappings.json -HContent-Type:application/json -XPUT 'localhost:9200/nginx'
mappings.json
{
  "mappings" : {
    "events": {
      "properties": {
        "timestamp" : {
          "type": "date",
          "format" : "epoch_millis"
        }
      }
    }
  }
}

Teljesítmény

Most, hogy van egy működő rendszerünk, jogosan merülhet fel a kérdés, hogy mégis mit várhatunk el tőle. Ennek kiderítéséhez egy másik dropletet veszünk igénybe, ami ugyanabban a datacenter-ben van, mint a szerverünk és privát hálózaton SSH tunnel-lel vannak összekötve.

A kliens gépen egy végtelenül egyszerű Python script egy szálon küld be a local rsyslog-ba 100k üzenetet, amit az továbbít a szerver rsyslog-jának, aki gondoskodik a lementésről.

from syslog import *
from time import sleep

for i in range(100000):
    syslog('performance test message: ' + str(i))
    sleep(0.0002)

Első körben fájlba mentjük az üzeneteket, hogy legyen mihez viszonyítani. Ez nagyjából 37 másodperc alatt zajlott le, miközben a szerver 50% körüli CPU terheltséget produkált, ami 160k körüli logsort jelent percenként.

Ugyanez Elasticsearch-be mentéssel 80-90% körül pörgette a CPU-t, közel 9 percig, ami úgy 11k logsor percenként. Nem annyira rossz, de vajon lehetne-e jobb? Nyilván, különben nem kérdeztem volna.

Az alapbeállítás soronként küldi be a logokat az Elasticsearch-be, ami érezhetően nem a legjobb választás ilyen mennyiségek mellett. Szerencsére van lehetőség a Bulk API használatára:

/etc/rsyslog.d/10-elastic.conf
action(type="omelasticsearch" template="syslog-json" bulkmode="on")

A terhelésen nem változtat, viszont alig több, mint egy perc alatt végez, amivel sikerült elérni a 88k log/percet. A lekérdezések terén szintén jónak tűnt a helyzet. A tesztek során több, mint 650k elem került az indexbe, de a felületen csak az adatbetöltések alatt lehetett lassulást érezni.

Ezzel a kis kísérletünk a végéhez közeledik. Úgy tűnik, hogy megoldható egy működő (sőt, használható), Elasticsearch alapú központi logolási rendszer beüzemelése egy 1 GB memóriával rendelkező gépen. Néhol kerülőkkel és kompromisszumokkal tarkított az út, de kétségtelenül megoldható.

Ha mégis kezdenénk kifogyni ebből a rengeteg erőforrásból, a Kibana (és ha szükségünk van rá, akkor a Logstash) átköltöztethető egy másik gépre és az Elasticsearch-ből is felhúzhatunk több példányt, hogy igazi klaszterünk legyen.