Szövegfeldolgozás régen és most

1979 nyara. Egy levegőtlen irodában ülsz a terminál mögött. Nézed a kurzor lassú villogását, miközben izzadtságcseppek gördülnek végig a hátadon. A szomszéd szobából áthallatszik a nagyszámítógép tompa zúgása.
Mögötted két nyomozó figyel feszülten. Életek múlhatnak azon, hogy valami nyomot találj a számítógép log fájljaiban. De hát több megabájtnyi adatról van szó! A közeli polcon megakad a szemed a "The C Programming Language" című könyv egy példányán. Rövid mérlegelés után elveted a lehetőséget. Nincs idő napokig pointerekkel fogócskázni.
Gondolataid lassan vánszorognak. Nem a legjobb napot választottad a kávéadagod csökkentésére. Mintha hallottál volna mostanában egy új nyelvről, amit pont szövegfájlok feldolgozására találtak ki. Valami három betűs... hmm... talán AWK? Már írod is a man awk parancsot, a megjelenő dokumentum első pár sorának átfutása után halvány mosoly jelenik meg az arcodon.
- Nos? - kérdezi az egyik nyomozó türelmetlenül.
- Megoldjuk. - mondod magabiztosan.

DEC VT100 terminál, az 1978-as év sztárja
(CC BY 2.0 image by Jason Scott)

Az AWK vitathatatlanul hasznos eszköz volt a maga idejében, de amikor a közelmúltban belefutottam egy AWK oktató cikkbe, azon kezdtem el gondolkodni, hogy érdemes-e még napjainkban is megtanulni vagy a kor gyengén típusos, szövegfeldolgozásban jeleskedő programozási nyelvei teljes mértékben elavulttá tették.

A vizsgálatok során a vetélytársak olyan nyelvek vagy eszközök lesznek, amik jó eséllyel már alapból telepítve vannak egy modern Linux-disztribúcióban.

AWK gyorstalpaló

Az AWK programok blokkokból állnak, egy blokk szűrő { parancsok } formátumú. A parancsok lefutnak minden egyes sorra, amire a szűrő igaz. A sort mezőkre bontja whitespace-ek mentén (változtatható) és az egyes mezők a $1..$n változókban elérhetőek. A szűrő opcionális, lehet például BEGIN, END, /regex/ vagy egy boolean feltétel, mint például $2 > 4.

Van pár beépített változó, amik közül az érdekesebbek az FS, amivel a elválasztó karaktert (vagy regexet) lehet megadni (például a BEGIN blokkban), az NF, ami az aktuális sor mezőinek a száma ($NF az utolsó mező értéke) és az NR, ami azt adja meg, hogy hányadik rekordnál (sornál) járunk.

Parancssori eszköz

Az egyik felhasználási mód, hogy az AWK programot rögtön a parancs paramétereként írjuk meg. Például a cat parancs awk megfelelője:

$ awk '{ print }' /etc/passwd

Ezen a téren az egyik kihívó a Perl nyelv lesz, aminek van awk-szerű működési módja:

$ perl -ae 'print' /etc/passwd

Valamint megnézzük, hogy egyéb Linux-on elérhető eszközökkel, mint a cut vagy a grep hogyan lehet ugyanazokat a problémákat megoldani.

A root felhasználó rekordjának utolsó mezője

Az /etc/passwd esetén ez nem akkora probléma, mivel fix mennyiségű oszlop van, de tegyük fel, hogy egy olyan fájlról van szó, ahol soronként változhat, hogy hányadik mező az utolsó.

$ awk -F: '$1 == "root" { print $NF }' /etc/passwd

$ perl -F: -le 'print $F[-1] if $F[0] eq "root"' /etc/passwd

$ grep '^root:' /etc/passwd | rev | cut -d: -f1 | rev

A Perl változat egy kicsit hosszabb, bár a grep-nél használt regex-es trükk itt is alkalmazható lenne (ahogy az awk esetén is). A shell script-es változatban a rev használata nem túl elegáns, de sajnos a cut nem tud olyat, hogy dinamikusan visszaadja az utolsó mezőt.

Azok a rekordok, ahol a user id nem egyezik a group id-val

$ awk -F: '$3 != $4 { print $1 }' /etc/passwd

$ perl -F: -le 'print $F[0] if $F[2] != $F[3]' /etc/passwd

$ grep -v ':\([0-9]\+\):\1:' /etc/passwd | cut -d: -f1

Az awk és a Perl-es változat itt is egész egyértelmű, a tömb elérések miatt a Perl itt is egy kicsivel hosszabb. A shell script-es változat backreference-es trükkje kevésbé olvasható megoldást eredményez.

Az összes user id összege

$ awk -F: '{ s += $3 } END { print s }' /etc/passwd

$ perl -F: -le '$s += $F[2]; END { print $s }' /etc/passwd

$ cut -d: -f3 /etc/passwd | paste -sd+ | bc

A Perl jó munkát végzett az awk másolásakor, nem is nagyon lehet mit hozzáfűzni. A shell script-es itt se túl egyértelmű, a paste a sorokból egy sort csinál, amit a + karakterrel fűz össze, a bc pedig kiértékeli a matematikai műveleteket.

A használt shell-ek népszerűségük szerint

$ awk -F: '{ x[$7]++ } END { PROCINFO["sorted_in"] = "@val_num_desc"; for (v in x) { print x[v], v } }' /etc/passwd

$ perl -F: -le '$x{$F[6]}++; END { print $x{$_}, " ", $_ for sort { $x{$b} <=> $x{$a} } keys %x }' /etc/passwd

$ cut -d: -f7 /etc/passwd | sort | uniq -c | sort -rn

Az awk-s megoldás tipikusan olyan, amit fejből nem valószínű, hogy csak úgy begépel az ember, ráadásul csak gawk-ban működik. A Perl-es se sokkal szebb, az asszociatív tömbök rendezése érték alapján egyik nyelvnek se kedvezett. A shell script viszont ez esetben egész kiemelkedően szerepelt.

Programozási nyelv

Egyszer csak eljutunk arra a pontra, hogy olyan programunk van, ami nem fér ki kényelmesen a parancssorban, többször is futtatnunk kell és ezért egy fájlba írjuk. Ezen a ponton úgy érzem, hogy az awk-nak már nincs helye.

Karbantarthatósági és tesztelhetőségi szempontokból elmarad a modern programozási nyelvektől, egy hosszabb életű script esetében pedig ezek már nem elhanyagolhatóak.

Nézzünk azért egy egyszerűbb példát:

BEGIN {
    FS = ":"
    count = 0
}

$3 != $4 {
    count += 1
    print "uid does not equal gid for user " $1 " (" $3 " vs " $4 ")"
}

END {
    print count " matching users"
}

Ez valahogy így nézhetne ki Python nyelven:

import fileinput

count = 0

for line in fileinput.input():
    fields = line.strip().split(':')

    if fields[2] != fields[3]:
        count += 1
        print(f'uid does not equal gid for user {fields[0]} ({fields[2]} vs {fields[3]})')

print(f'{count} matching users')

Nem mondható szörnyűnek, de ha valami awk-hoz hasonlót szeretnénk, akkor sem kell a Python-t hátrahagynunk. Írhatunk egy kis modult, hogy leutánozzuk a szerkezetét:

from my_awesome_file_processing_module import run

def begin(ctx):
    ctx.FS = ':'
    ctx.count = 0

def uid_does_not_equal_gid(ctx, fields):
    if fields[2] != fields[3]:
        ctx.count += 0
        print(f'uid does not equal gid for user {fields[0]} ({fields[2]} vs {fields[3]})')

def end(ctx)
    print(f'{ctx.count} matching users')

run(begin, end, [uid_does_not_equal_gid])

Vagy egy kicsivel több munkával még a tömbös eléréstől is megszabadulhatunk:

from my_awesome_file_processing_module import begin, end, line, run

@begin()
def begin(ctx):
    ctx.FS = ':'
    ctx.count = 0

@line(lambda _3, _4: _3 != _4)
def uid_does_not_equal_gid(ctx, _1, _3, _4):
    ctx.count += 0
    print(f'uid does not equal gid for user {_1} ({_3} vs {_4})')

@end()
def end(ctx)
    print(f'{ctx.count} matching users')

run()

Összegzés

Ha Perl mágus vagy, nagy valószínűséggel nincsen szükséged az awk-ra, sem mint parancssori eszközre, sem mint programozási nyelvre.

Ha shell script-ek írásával töltöd időd jó részét, akkor is egész jól el tudsz boldogulni awk nélkül, de már egy minimális awk tudás is hasznos tagja lehet az eszközkészletednek, mivel egyszerűbb, jobban érthető scripteket eredményezhet.

Ha járatos vagy bármilyen más script nyelvben, valószínűleg jobban jársz ha awk helyett abban írsz hosszabb lélegzetvételű programokat.

Ezektől függetlenül egy érdekes eszközről van szó, amit a gyakorlatban való alkalmazhatóságától függetlenül érdemes lehet kicsit tanulmányozni. Minden nyelvből lehet valamit tanulni, ha mást nem, elrettentő példákat.

Adatsorok és grafikonok

Réges-régen kezdődött egy Raspberry Pi Model A-ra kötött DS18B20 hőmérséklet szenzorral. Cron futtatta meg 5 percenként a kis Python scriptet, ami lekérte a szenzor adatait és letárolta egy SQLite adatbázisban. Egy másik script óránként generált az adatokból gyönyörű SVG grafikonokat Pygal segítségével.

Egy a régi grafikonok közül

Telt-múlt az idő, a szenzor lecserélődött egy HTU21D-F modellre, ami egy kicsit pontosabb volt és már páratartalmat is tudott mérni. Aztán egy BME680-ra, ami légnyomás és levegőminőség adatokat hozott magával. A Raspberry Pi sem ragadt le a múltban, két szenzor csere között frissült Zero W-re.

A grafikon generáló script valahol menet közben elromlott, de senkinek sem hiányzott annyira, hogy megjavítsa. A mérési adatok viszont továbbra is rendületlenül érkeztek az adatbázisba. Egészen 2017 novemberéig, amikor is elkezdtek 5 percenként jönni a levelek a gépről, hogy valami miatt nem fut le a script. Gyors megoldásként ki lett véve a megfelelő sor a crontab-ból, hogy majd ha hazaérek, megjavítom.

Ugrás 2018 augusztusára, ahol történetünk lényegében elkezdődik. Ekkor realizáltam, hogy már lassan egy éve nem jönnek az adatok, rendbe kellene rakni. Ez gyakorlatban egy újraindítást jelentett, amitől varázslatos módon megjavult, de amit érdemes megcsinálni, azt érdemes túlbonyolítani is. Elérkezett az idő, hogy a régi cron-os, SQLite-os, nem működő grafikonos megoldás helyét valami modernebb dolog vegye át.

Tárolás

Manapság az ilyen jellegű adatokat time series adatbázisban trendi tárolni, úgyhogy kerestem is egy szimpatikusat. A választás az InfluxDB-re esett, de senki se emlékszik már pontosan, hogy miért. Annyi biztos, hogy ARM és Pi kompatibilis, egyszerűen telepíthető és használható.

# wget https://dl.influxdata.com/influxdb/releases/influxdb_1.6.1_armhf.deb
# dpkg -i influxdb_1.6.1_armhf.deb
# service influxdb start

A letöltési oldalon megtalálható a legfrissebb verzió, annyi csak a trükk, hogy nincs listázva az ARM-es deb csomag, de ha az "Ubuntu & Debian" résznél szereplő URL-ben átírjuk az amd64-et armhf-re, akkor simán működik. Első körben a kis Python script lett kibővítve, hogy az adatbázis mellett az InfluxDB-be is küldje be az adatokat.

import requests

url = 'http://127.0.0.1:8086/write?db=metrics&precision=s'
data = 'environment temperature={},humidity={} {}'.format(temp, hum, int(timestamp))

requests.post(url, data=data, headers={'Content-Type': 'application/octet-stream'})

Ez után készült egy migrációs script is, amivel a korábbi adatok is átkerültek InfluxDB-be. A select query-ből jól látszik, hogy az első szenzor csak hőmérsékletet tudott mérni, a páratartalom csak később lett hozzáragasztva.

import sqlite3
import os
import requests

conn = sqlite3.connect('data.sq3')
c = conn.cursor()

rows = []
for row in c.execute('select date, value, humidity from temp_logs order by id'):
    if row[2]:
        rows.append('environment temperature={},humidity={} {}'.format(row[1], row[2], int(row[0])))
    else:
        rows.append('environment temperature={} {}'.format(row[1], int(row[0])))

url = 'http://127.0.0.1:8086/write?db=metrics&precision=s'
headers = {'Content-Type': 'application/octet-stream'}
batch_size = 10000

for i in xrange(0, len(rows), batch_size):
    data = '\n'.join(rows[i:i + batch_size])
    requests.post(url, data=data, headers=headers)

Megjelenítés

Az InfluxDB fejlesztői egy egész TICK (Telegraf, InfluxDB, Chronograf, Kapacitor) stack-nek nevezett megoldást szállítanak, amiből a Chronograf képes a tárolt adatok böngészésére és dashboard-okon való megjelenítésére. Ezzel mit sem törődve a Grafana-t választottam az adatbázisom frontendjeként. Hasonlóan egyszerűen telepíthető jószágról van szó, a gyárilag jövő konfigurációval se kell sokat babrálni és még a letöltés sem igényel a korábbihoz hasonló trükközést.

# wget https://s3-us-west-2.amazonaws.com/grafana-releases/release/grafana_5.2.2_armhf.deb
# dpkg -i grafana_5.2.2_armhf.deb
# service grafana-server start

Az új Grafana dashboard

Boldogan böngészhettem az adataimat, de azért négy idősor nem ad okot túl sok boldogságra. Még több metrikát kell szerezni! Szerencsére ennek a TICK-nek az egyik tagját, nevezetesen a Telegraf-ot pont erre találták ki. Csak feltelepítjük egy (vagy több) gépre, beállítjuk az InfluxDB elérhetőségét és már özönlenek is az adatok a CPU terheltségéről, a partíciók állapotáról vagy éppen a memória kihasználtságról, hogy csak néhányat említsek.

[[outputs.influxdb]]
  urls = ["http://127.0.0.1:8086"]

A legjobb, hogy még csak a grafikonokat sem kell kézzel legyártanunk, a Grafana oldaláról néhány kattintással beimportálhatóak a Telegraf által generált adatokat vizualizáló dashboard-ok (mint például ez vagy ez).

Telegraf dashboard

Ütemezés

Az utolsó lépés a cron kiváltása volt. Micsoda véletlen, hogy pont feltelepült egy Telegraf, ami jeleskedik a metrikák ütemezett gyűjtésében. Csak rá kell bírni, hogy a szenzor adatait is elvigye.

Szerencsére nem igényelt sok győzködést, egy meghívható parancsra van szüksége, ami megfelelő formátumban adja vissza az adatokat.

[[inputs.exec]]
  commands = ["/usr/local/bin/query_sensor.sh"]
  timeout = "5s"
  data_format = "influx"

A script is átesett még egy utolsó módosításon, hogy a közvetlen adatbázis kapcsolat helyett inkább csak a kimenetre írja ki az adatokat és ezzel a régi megoldás utolsó eleme is felszámolásra került. Az új rendszer pedig azóta is problémák nélkül gyűjti a különböző információkat.

Játékos programozás

Nem emlékszem már, hogy mi lehetett az első programozós játék, amivel találkoztam, de valami miatt a legemlékezetesebb a Manufactoria volt. A Flash játékok korszakának egy igazi gyöngyszeme. Kész csoda, hogy ennyi év után még sikerült megtalálni, főleg, hogy csak annyira emlékeztem belőle, hogy valami robotos és futószalagos.

A történet szerint tesztkészülékeket kell építenünk, hogy kiszűrjük a hibás robotokat. Később pedig, ahogy az eszköztárunk bővül, már át is kell programoznunk őket, hogy megjavuljanak.

Manufactoria

Talán egy kicsit kilóg a sorból, első ránézésre nem is tűnik programozásnak (pedig még egzotikus programozási nyelvet is csináltak belőle), de ahogy haladunk a nehezebb és nehezebb pályák felé, úgy kezd egyre inkább egy formális nyelvek és automaták gyakorlatra emlékeztetni.

Érdemes az első megoldás felett érzett túláradó öröm után még visszatérni a feladatra és megpróbálni kevesebb elemből megoldani. Sajnos a játék nem nagyon támogatja ezt, nem lehet egyszerre több megoldásunk egy pályához, de egy URL formájában elmenthetjük a megoldást kézzel.

Megoldás optimalizálás előtt és után

Vizuális programozás

A Human Resource Machine akár egy leegyszerűsített Scratch is lehetne, amiben a drag and drop szerkesztő segítségével kell irodai dolgozókat rábírnunk a munkára egy olyan irodában, ahol gyanúsan sok a megoldandó logikai feladvány.

Human Resource Machine

Ahogy haladunk előre a játékban, úgy kapunk egyre több építőelemet a programjainkhoz. Feladatonként három megoldást tárolhatunk, amire szükségünk is lesz, ha az extra kihívásokat is teljesíteni szeretnénk, amikben méretre (használt utasítások száma) és sebességre (lefuttatott utasítások száma) kell optimalizálni a programokat.

Egyszerű program méretre és sebességre optimalizálva

A bejegyzés írásakor még csak készülőben volt a játék folytatása 7 Billion Humans néven, ahol már irodai dolgozók egész hadával vethetjük bele magunkat a párhuzamos programozás gyönyöreibe egy még inkább Scratch-re emlékeztető felület használatával.

7 Billion Humans

A Manufactoria fejlesztője is készített később egy vizuális szerkesztővel rendelkező programozós játékot, ami a Silicon Zeroes nevet viseli. Kipróbálni még nem volt alkalmam, de a képek és YouTube videók alapján elég érdekesnek tűnt ahhoz, hogy azért megemlítsem.

Silicon Zeroes

Rekreációs programozás Assembly nyelven

A Human Resource Machine könnyed kinézete után egy erős váltás a Zachtronics által fejlesztett TIS-100, amiben egy érdekes architektúrájú számítógépet kell assembly és párhuzamos programozás erejével a feladatok megoldására bírnunk.

TIS-100

A spártai felülettel remekül harmonizál a játékhoz mellékelt 14 oldalas PDF dokumentum a nyelv leírásával, ami a tutorial-t is hivatott helyettesíteni.

Itt is három megoldást tarthatunk meg egy feladathoz. A programokat sebességre, használt node-ok számára és méretre optimalizálhatjuk. A pálya sikeres végrehajtása után kapunk három hisztogramot, hogy ebben a három metrikában hogyan teljesít a programunk a többi játékos megoldásához képest.

A TIS-100 fejlesztőinek egy másik játéka a SHENZHEN I/O. A kinézetre már sokkal barátságosabb játékban egy kínai elektronikai cég új alkalmazottjaként különböző áramkörök megtervezése és felprogramozása a feladatunk. A szereppel való azonosulást elősegíti, hogy a játék egy operációs rendszernek néz ki, a feladatokat email-ben kapjuk és még egy pasziánsz is van a "gépünkön".

SHENZHEN I/O

Nem csak a játék fejlődött a TIS-100 óta, hanem a dokumentációt is egy új szintre emelték. Ebben a játékban már egy 47 oldalas PDF-et kapunk, ami a programozási nyelv (assembly) és a kitalált elektronikai komponensek leírását tartalmazza. Hangulatra teljesen hozza a valódi komponensekhez adott dokumentációkat.

Az elmenthető megoldások száma ebben a játékban nincs korlátozva. A dizájnokat gyártási költség (használt komponensek ára), energia felhasználás (lefuttatott utasítások száma) és a program mérete szerint optimalizálhatjuk. A pálya sikeres megoldása után - a Zachtronics játékoknál megszokott módon - hisztogramokat is kapunk arról, hogy ez mennyire sikerült.

Ha már a programozás játék változatát is unjuk, de továbbra is valami olyasmire vágyunk, ami megmozgatja agyunk ritkán használt tekervényeit, érdemes a Zachtronics által fejlesztett többi logikai játékot is megnézni, mint például az Infinifactory, az Opus Magnum vagy a SpaceChem.

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.

Log gyűjtés, egy kicsit másképp

CC0 image by StockSnap

Ma a központosított logolásról lesz szó. No nem arról a szintről, amikor az alkalmazásod több tíz gigányi logot termel naponta és azt kellene valahova elpakolnod. Arra ott a méltán híres ELK stack. Nem, mi maradunk a hobbi szintnél, amikor van néhány géped, amik lehet, hogy egész életük során összesen nem látnak majd több tíz gigányi logot.

Elképzelhető, hogy nagyobb forgalom mellett is működhet egy ilyesmi felállás, de odáig nem jutott el ez a kis projekt, hogy méréseket is végezzek. Kicsit korábban sikerült már akadályokba ütközni, de erről majd később, kezdjük az elején.

A központosítás

Minden (jó linuxos) háztartásban megtalálható egy syslog. Most konkrétan az rsyslog változatával fogunk foglalkozni, de az elv valószínűleg a többivel is működhet. Először is szükségünk van egy központi szerverre, aminek küldhetjük az adatokat. Szerencsénkre az rsyslog-nak megmondhatjuk, hogy legyen olyan kedves és kívülről is fogadjon be logsorokat:

/etc/rsyslog.conf
module(load="imtcp")
input(type="imtcp" port="514")

Amit itt érdemes tudni, hogy ez egy plain text kommunikáció, így ha féltjük a logjainkat a gonosz kémektől, gondoskodnunk kell a biztonságukról. Az rsyslog tud TLS-en is kommunikálni, de felhúzhatunk egy SSH tunnel-t vagy VPN-t is a gépek között. A következő parancs segítségével kipróbálhatjuk, hogy minden jól működik-e:

$ logger -n <központi szerver> -P 514 -T "Test message"

Ezek után már csak a kliens gépeket kell beállítani, hogy továbbítsák a logjaikat a központba:

/etc/rsyslog.d/10-forward.conf
action(type="omfwd" Target="<központi szerver>" Port="514" Protocol="tcp")

És kész is vagyunk. Köszönöm a figyelmet, gyertek máskor is.

Az adatbázis

Na jó, nem ússzátok meg ennyivel. Az igaz, hogy egy központi gépen vannak a logjaink, de még mindig csak fájlokban. Mi lenne, ha mondjuk inkább MongoDB-be pakolnánk?

Nyilván nem sokkal lennénk előrébb, ha csak soronként bedobálnánk őket egy adatbázisba. Viszont ha valami egyszerűen feldolgozható formátumban érkeznének, mondjuk JSON-ként...

/etc/rsyslog.d/10-forward.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="\"}")
}

action(type="omfwd" template="syslog-json" Target="<központi szerver>" Port="514" Protocol="tcp")

Most már futhat valami service a központi gépen, ami figyeli a logfájlokba érkező új sorokat és betolja őket az adatbázisba. Vagy akár írhatunk egy egyszerű log fogadó szervert is, ami közvetlenül adatbázisba menti az érkező sorokat.

server.js
const net = require('net');
const readline = require('readline');
const MongoClient = require('mongodb').MongoClient;

(async () => {
  const host = '127.0.0.1';
  const port = 514;
  const connstring = 'mongodb://localhost:27017';

  const db = (await MongoClient.connect(connstring)).db('logging');

  net.createServer(socket => {
    const rl = readline.createInterface(socket, socket);
    rl.on('line', async data => {
      let jsonData = JSON.parse(data.toString().trim());
      jsonData.timestamp = new Date(jsonData.timestamp);

      await db.collection('syslog').insertOne(jsonData);
    });
  }).listen({ host, port, exclusive: true });
})();

A syslog protokol nem egy bonyolult jószág, a konkrét logsorokat küldi, így soronként egy-egy JSON-t kapunk, ami mehet is az adatbázisba. Vagy mentés előtt még végezhetünk rajta módosításokat, ha szükségesnek látjuk (például a dátumot string-ként tartalmazó mezőt Date objektummá alakíthatjuk).

Ezen a ponton megvan minden log a szervereinkről... amik syslog-ba érkeznek. Mi a helyzet a többivel? Ha az alkalmazás elég okos, akkor tud direktbe logolni a központi szerverre JSON formátumba. Vagy küldheti a logokat a lokális rsyslog-nak, ami majd továbbítja őket a központba.

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

if $syslogfacility-text == "local7" then {
  action(type="omfwd" template="json-msg" Target="<központi szerver>" Port="514" Protocol="tcp")
  stop
}

Itt a local7 facility-re érkező logoknál arra számítunk, hogy a log üzenet már egy valid JSON, így a többi részét figyelmen kívül hagyhatjuk és csak azt továbbítjuk.

Alább pedig az látható, hogy az nginx-et (1.11.8-as verziótól) hogyan tudjuk rábírni arra, hogy JSON formátumban küldje a logjait az rsyslog-nak. A local7 facility nála az alapbeállítás, úgyhogy azzal nem is kell törődnünk.

/etc/nginx/conf.d/10-logformat.conf
log_format json escape=json '{"timestamp": $msec, '
  '"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"}';

access_log syslog:server=unix:/dev/log,nohostname json;

A megjelenítés

Itt kezdtek felmerülni a problémák. A MongoDB egyértelmű választásnak tűnt még azon a ponton, amikor JSON dokumentumokat kellett tárolni, de ha egy Kibana szerű felületet is szeretnénk hozzá, akkor már nem érződik annyira jó döntésnek.

Persze mindig ott a lehetőség, hogy megírunk magunknak egy hasonló felületet. Megfelelően kicsi scope mellett talán van is esély a befejezésre, de ez azért távol áll az ideális helyzettől. Némi keresés után a Redash-t sikerült még megtalálnom. Támogatja a MongoDB-t, tud grafikonokat generálni az adatokból és van lehetőség mentett lekérdezésekre is.

Query szerkesztő

Példa dashboard

Határozottan kényelmetlenebbnek érződik, mint a Kibana. Főleg a lekérdezések összerakása (ami egy hatalmas JSON), de a grafikonok se olyan kényelmesek/okosak. Annyi előnye azért még biztos van, hogy nem kell lefejleszteni.

Összességében egy remek hétvégi program volt kicsit közelebbről megismerkedni a syslog-gal és megpróbálni összerakni egy alternatív megoldást. Csak ajánlani tudom mindenkinek, mint tapasztalatszerzési lehetőséget. Viszont ha éles rendszerek központi logolásáról van szó, lehet, hogy jobban járunk a kitaposott ösvényekkel.

Összes bejegyzés