Mentat

Používají se správně indexy? Co variace různě zadaných/nezadaných polí? Bylo by vhodné jiné indexy udělat nebo naopak zrušit? Optimální by bylo, aby se využily indexy na všechna zadaná pole, je možné, že na to budou potřeba složené.

Není problém s {"Alert.Analyzer.@analyzerid":""}? Proč tam vlastně je?

Vhodné by bylo nasimulovat si variace dotazů a podívat se na explainy.

SOURCE IP AND DETECTOR
TARGET IP AND DETECTOR

MongoDB filter:[FIND] Filter '{"$and":[{"Alert.Source.Node.Address.ipv4.ip":"015D22D6"},{"$and":[{"Alert.Analyzer.@analyzerid":""},{"Alert.Analyzer.@name":""}]}]}' with sorting '{"Alert.DetectTime.@ntpstamp":-1}' with limit '30'

db.alerts.find({"$and":[{"Alert.Source.Node.Address.ipv4.ip":"015D22D6"},{"$and":[{"Alert.Analyzer.@analyzerid":"au1-pickup"},{"Alert.Analyzer.@name":"LaBrea"}]}]}).explain()
{
        "cursor" : "BtreeCursor Alert.Source.Node.Address.ipv4.ip_1",
...
        "indexBounds" : {
                "Alert.Source.Node.Address.ipv4.ip" : [
...
}

db.alerts.find({"$and":[{"Alert.Source.Node.Address.ipv4.ip":"015D22D6"},{"$and":[{"Alert.Analyzer.@analyzerid":"au1-pickup"},{"Alert.Analyzer.@name":"LaBrea"}]}]}).explain()
{
        "cursor" : "BtreeCursor test2",
...
        "indexBounds" : {
                "Alert.Source.Node.Address.ipv4.ip" : [
...
                "Alert.Analyzer.@analyzerid" : [
...
                "Alert.Analyzer.@name" : [
...
}

Tohle se výrazně zlepšilo! Variace různých polí se mi teď vracejí vcelku svižně.

Zádrhel bude ale ještě nejspíš u rozsahů:

Na ostrém dotaz na source 109.227.213.155/24 and dest 195.113.251.178/24 vytikává; stejně tak dotaz pouze na source 109.227.213.155/24.

Ovšem po konzultaci s Mekem nás to překvapuje, protože to vypadá, že na ostrém žádné nové indexy nejsou.

Bylo by potřeba, abychom byli připraveni na seminář - přihoď pls i info, co jsi udělal tady - a pokud je potřeba, aby Mek něco pullnul či vybuildil indexy, je to potřeba co nejdříve (indexy se taky můžou stavět den).

Ad ostry) Zadne indexy jsem tam nedodaval, ale o vikendu je tam dodam, viz tento pozadavek.
Ad pull) Na pullu se s Mekem ted domluvim, mam tam minimalne opravu v devel kodu.

Na ostrém dotaz na source 109.227.213.155/24 and dest 195.113.251.178/24 vytikává; stejně tak dotaz pouze na source 109.227.213.155/24.

Jakmile o vikendu rucne nasadim indexy, ihned toto overim.

Diky, R.

• update na 2.6
• proč nepoužívá indexy z webového rozhraní? špatné konverze? (při pokusech na string nepoužil indexy, na bindata ano)
• možná problém, že máme mnoho zapisujících procesů, které zamykají db/indexy?
• Index Intersection v 2.6? (http://docs.mongodb.org/manual/core/index-intersection/)

• možná má 2.6 detailnější pohledy na plán (http://docs.mongodb.org/manual/reference/method/js-plan-cache/)

• mluvili jsme o prohození pořadí položek ve složeném indexu, kvůli kardinalitě - zkus ještě jednou a pozor na skutečné pořadí (hash/ixhash) a jména indexů

Zdá se, že Mongo vybírá indexy (které pasují) podle pořadí vytvoření indexu (WTF?), místo aby použilo složený index s odpovídající sadou polí. Zatím nemáme jinou možnost, než s tím žít, tj.:

• na ostrý s tím - přegenerovat potřebné indexy ve správném pořadí, pozor na zamykání na pozadí pro zápis, na ostrý klienti pořád píší
• ts a ts_u ponechat

Tím ale nezavíráme - bude chtít zjistit víc - jaký je v Mongu mechanismus, jestli něco nepřehlížíme, zda by nešlo Mongo znásilnit lépe, etc. "verbose" u explainu, tj. jaké plány a proč bere v úvahu a vybírá?

Index Intersection nám zřejmě úplně nepomůže, podle diskusí Mongo umí použít max dva současně.

Logování explainu:

• do logu jen explain.cursor
• (případně do devel toolbaru celý explain (klidně verbose))

S Mekem jsme otestovali, ze parametr background pri vytvareni indexu zajisti nezamykani kolekci - aby byla zachovana spravna funkcnost (cteni/zapis).

Dale jsme se s Mekem domluvili, ze za kazdou cenu musim ponechat indexy ts a ts_u.

R.

Pavel Kácha wrote:

Zdá se, že Mongo vybírá indexy (které pasují) podle pořadí vytvoření indexu (WTF?), místo aby použilo složený index s odpovídající sadou polí. Zatím nemáme jinou možnost, než s tím žít, tj.:

• na ostrý s tím - přegenerovat potřebné indexy ve správném pořadí, pozor na zamykání na pozadí pro zápis, na ostrý klienti pořád píší
• ts a ts_u ponechat

Tím ale nezavíráme - bude chtít zjistit víc - jaký je v Mongu mechanismus, jestli něco nepřehlížíme, zda by nešlo Mongo znásilnit lépe, etc. "verbose" u explainu, tj. jaké plány a proč bere v úvahu a vybírá?

Index Intersection nám zřejmě úplně nepomůže, podle diskusí Mongo umí použít max dva současně.

Pavel ma ve svych Alerts dotazech ulozeny nasledujici:

User queries
- Test (simple)
- Slow - range (simple)
- Slow - source, detector, class (simple)

Vsechny tri jsem si vytvoril pod svym uzivatelem a jsou provedeny rychle.
Myslim si, ze je to tedy posun k lepsimu.
Pavle, muzes to testnout?
Pokud narazis na nejaky dalsi pomaly dotaz, dej vedet.

Zkousel jsem rozsah VSB (Source = 158.196.0.0/16):
Viewing duration: 4m 30s

Kdyz jsem dotaz vice omezil (Source = 158.196.0.0/16 && Class = Botnet B58-DGA2), tak rychlost byla:
Viewing duration: 1.0445s

R.

Source = 94.156.57.0/24 && Detector = mentat-wardenin/honeyscan && Class = Probe trvá 8 minut

Zajímavé, na druhý pokus 107 vteřin. Obávám se, že nám do toho leze kešování a tím pádem jsou výsledky nekonzistentní.

Nejenom to.. dokazu si predstavit, ze u detectoru za to muze i find bez Tie::IxHash.
Samotny Source: 94.156.57.0/24 20.0829s
Ja ted pro tu indexaci udelal v Alerts maximum:(

Budeme navic chytrejsi, az budeme mit logovani pouzivani indexu.

R.

Stejne indexy jsou na dev a ostrem. Pouziti indexu z konzole (bez ovlivneni ixhash) je na obou serverech jine (pravdepodobne diky jine verzi mongodb - 2.4.x verzus 2.6.x).

Ostry (evidentne spatne):

db.alerts.find({"$and":[{"Alert.Source.Node.Address.ipv4.min":{"$gte": HexData(0, "5E9C3900")},"Alert.Source.Node.Address.ipv4.max":{"$lte": HexData(0, "5E9C39FF")}},{"$and":[{"Alert.Classification.@text":"Probe"},{"$and":[{"Alert.Analyzer.@analyzerid":"mentat-wardenin"},{"Alert.Analyzer.@name":"honeyscan"}]}]}]}).explain()
{
        "cursor" : "BtreeCursor analyzername",

Dev (dokazal bych si predstavit, ze je to spravne):

db.alerts.find({"$and":[{"Alert.Source.Node.Address.ipv4.min":{"$gte": HexData(0, "5E9C3900")},"Alert.Source.Node.Address.ipv4.max":{"$lte": HexData(0, "5E9C39FF")}},
{"$and":[{"Alert.Classification.@text":"Probe"},{"$and":[{"Alert.Analyzer.@analyzerid":"mentat-wardenin"},{"Alert.Analyzer.@name":"honeyscan"}]}]}]}).explain()
{ 
        "cursor" : "BtreeCursor sourcecidr_and_targetcidr_and_detecttime_and_detector_and_class",

Pavel Kácha wrote:

Zdá se, že Mongo vybírá indexy (které pasují) podle pořadí vytvoření indexu (WTF?), místo aby použilo složený index s odpovídající sadou polí.

Az parametr verbose mi celou vec objasnil. Na mentat-dev to proste tak vypadalo. Teprve az jsem zacal pouzivat explain s verbose a mam identicke indexy (ostry a dev), zjistuji, ze na poradi skutecne nezalezi (reakce na WTF?).

Zatím nemáme jinou možnost, než s tím žít, tj.:

• na ostrý s tím - přegenerovat potřebné indexy ve správném pořadí, pozor na zamykání na pozadí pro zápis, na ostrý klienti pořád píší
• ts a ts_u ponechat

Splneno. FYI, pregenerovani trvalo cca 12 hodin (respektive 849m7.885s). Pri tvorbe indexace byla zachovana funkcnost (zapis a cteni).

Tím ale nezavíráme - bude chtít zjistit víc - jaký je v Mongu mechanismus, jestli něco nepřehlížíme, zda by nešlo Mongo znásilnit lépe, etc. "verbose" u explainu, tj. jaké plány a proč bere v úvahu a vybírá?

Ano, prehlizel jsem. Zde zabral tebou navrhovany "verbose" explain.

Index Intersection nám zřejmě úplně nepomůže, podle diskusí Mongo umí použít max dva současně.

To je otazka, protoze jiz Complex plan konecne vidim. Opet diky verbose.
Neprijemne pro me ted je, ze mame rozdilnou verzi na ostrem a devu.

Nemohu overit, co presne za index nabidne dotazu pres webove rozhrani (nezohledneno ixhash):

Source = 94.156.57.0/24 && Detector = mentat-wardenin/honeyscan && Class = Probe trvá 8 minut

Prepsano:

db.alerts.find({"$and":[{"Alert.Source.Node.Address.ipv4.min":{"$gte": HexData(0, "5E9C3900")},"Alert.Source.Node.Address.ipv4.max":{"$lte": HexData(0, "5E9C39FF")}},{"$and":[{"Alert.Classification.@text":"Probe"},{"$and":[{"Alert.Analyzer.@analyzerid":"mentat-wardenin"},{"Alert.Analyzer.@name":"honeyscan"}]}]}]})

Diky "verbose" explain zjisteno

Na ostrem voli misto indexu "sourcecidr_and_targetcidr_and_detecttime_and_detector_and_class" index "analyzername".
Duvodem je (moje spekulace!) pocet skenovanych dokumentu / polozek v indexu - nscanned, ktery je u "analyzername" mensi.

Doba behu - "millis" : 28879

        "cursor" : "BtreeCursor sourcecidr_and_targetcidr_and_detecttime_and_detector_and_class",
        "n" : 60,
        "nscannedObjects" : 60,
        "nscanned" : 758009,

        "cursor" : "BtreeCursor analyzername",
        "n" : 60,
        "nscannedObjects" : 758003,
        "nscanned" : 758003,

Pokud na ostrem u stejneho dotazu vynutim hintem index, ktery chci "sourcecidr_and_targetcidr_and_detecttime_and_detector_and_class", pak se cas zlepsi.. . Ziskal jsem samozrejme stejny vysledek (pocet dokumentu).

Doba behu - "millis" : 3093

V tuto chvili netusim, proc si na devu (novejsi) mongodb vybira z meho pohledu spravnejsi index, ale pokud se nepletu, pak je to diky intersection, ktera se mi u stejneho dotazu konecne objevuje (opet diky verbose):

...                
                {
                        "cursor" : "Complex Plan",
                        "n" : 0,
                        "nscannedObjects" : 0,
                        "nscanned" : 32,
                        "nChunkSkips" : 0
                },
                {
                        "cursor" : "Complex Plan",
                        "n" : 0,
                        "nscannedObjects" : 0,
                        "nscanned" : 32,
                        "nChunkSkips" : 0
                },
                {
                        "cursor" : "Complex Plan",
                        "n" : 0,
                        "nscannedObjects" : 0,
                        "nscanned" : 61,
                        "nChunkSkips" : 0
                },
                {
                        "cursor" : "Complex Plan",
                        "n" : 0,
                        "nscannedObjects" : 0,
                        "nscanned" : 32,
                        "nChunkSkips" : 0
                }
...

Pavel Kácha wrote:

Logování explainu:

• do logu jen explain.cursor

Thu May 15 12:16:16 2014 mentat-dev hawat_fastcgi_devel.pl[26073]: INFO: [MMSM] Executing MongoDB command:
 [FIND] Filter '{"$and":[{"Alert.Analyzer.@analyzerid":"au1"},{"Alert.Analyzer.@name":"X2"}]}' with sorting
'{"Alert.DetectTime.@ntpstamp":-1}' with limit '30'

Thu May 15 12:16:16 2014 mentat-dev hawat_fastcgi_devel.pl[26073]: INFO: [MMSM] MongoDB index: BtreeCursor detector

• (případně do devel toolbaru celý explain (klidně verbose))

Database queries
[27] Find alerts: [FIND] Filter '{"$and":[{"Alert.Analyzer.@analyzerid":"au1"},{"Alert.Analyzer.@name":"X2"}]}' with sorting
'{"Alert.DetectTime.@ntpstamp":-1}' with limit '30'

[27] Indexes: {"nscannedObjectsAllPlans":169,"filterSet":"0","cursor":"BtreeCursor detector","nscannedObjects":169,
"millis":910,"nscannedAllPlans":169,"scanAndOrder":"0", "server":"mentat-dev:27017","isMultiKey":"0","n":169,"stats":
{"needFetch":8,"yields":10,"works":178,"needTime":0,"children": [{"yields":10,"boundsVerbose":"field #0['Alert.Analyzer.@analyzerid']:
[\"au1\", \"au1\"], field #1['Alert.Analyzer.@name']: [\"X2\", \"X2\"]",
...

Rozchází se nám kód (např. ixHash) a verze db na ostrém a nedá se testovat. Tudíž:

• opravit fetch (mongodump + mongorestore, NE mongoexport/import) #1606
• dotlačit kód do funkčního stavu
• otestovat readonly hawata na mentat-dev proti mongu 2.4 na ostrém
• balíky, import na ostrý
• upgrade Mongo 2.4 na 2.6

Pak bude pokračovat výkonové ladění na mongo-dev + ověřování na ostrém.

Nasel jsem drobnou chybu, ale mozna dulezitou v indexech:

        {
                "v" : 1,
                "key" : {
                        "Alert.DetectTime.@ntpstamp" : NumberLong(-1),
                        "Alert.Classification.@text" : NumberLong(1),
                        "Alert.Analyzer.@analyzerid" : NumberLong(1),
                        "Alert.Analyzer.@name => 1" : null
                },
                "name" : "detecttime_and_detector_and_class",
                "ns" : "mentat.alerts",
                "background" : true
        }

Stalo by za to udelat reindex i s ohledem na reverzni indexy (kvuli sort - create/detect time), ktere nebyly mnou vytvareny.

opravit indexy (#1450)

O vikendu jsem smazal a znovu vytvoril vsechny indexy na ostrem mentatu -> poresil jsem tim chybu REVERS INDEX, dale pak indexy s "Alert.Analyzer.@name => 1" : null.

mongo hlásí krátký průběh dotazu, ale webové rozhraní ale laguje (zřejmě patří také hlavně do #1450)

Resim to jiz delsi chvili na MENTAT-DEV a zatim jsem se nedostal k pricine.. . Nicmene, casovy nesoulad tam je. Pokud najdu jeste chvili, zkusim se dostat dale.

Vysledky rucniho skriptu..

PRES NASI VRSTVU

($alerts, $count_all) = $storage1->find_msg($filter, $sort, $limit, $skip);
Count_all: 7, time: 6.26

WEBOVE ROZHRANI

Viewing duration: 6.9075s
Displaying entries 1 to 7

Informace z indexu:
millis: 2491
"n":7

MIMO NASI VRSTVU

my $result = $storage2->find($filter);
Time: 0.00

Zpracovani dat v cyklu..
while (my $record = $result->next()) {
...
}
Count_all: 7, time: 1.26

Informace z indexu:
Count_all: 7, millis: 1250

Tak jsem sel do knihovny, ktera je nasi nadstavbou nad mongem a ze srandy jsem zakomentoval nasledujici...

lib/Mentat/Storage/Mongo.pm

sub find_i(;$$$$$)

...
        #my $count = $cursor->count();
        my $count = 7;

#       # Apply the projection
#       if ($projection) {
#               Log::Loger->debug(__PACKAGE__, "[MMSM] Projecting results") if $DEVEL;
#               $cursor = $cursor->fields($projection);
#       }
#
#       # Apply the sorting
#       if ($sort) {
#               Log::Loger->debug(__PACKAGE__, "[MMSM] Sorting results") if $DEVEL;
#               $cursor = $cursor->sort($sort);
#       }
#
#       # Skip few first records
#       Log::Loger->debug(__PACKAGE__, "[MMSM] Skiping '$skip' results from beginning") if $DEVEL;
#       $cursor = $cursor->skip($skip) if ($skip > 0);
#
#       # Return limited number of records
#       if ($limit > 0) {
#               Log::Loger->debug(__PACKAGE__, "[MMSM] Limiting results to max '$limit'") if $DEVEL;  
#               $cursor = $cursor->limit($limit);
#       }
#       else {
#               Log::Loger->debug(__PACKAGE__, "[MMSM] Results are unlimited") if $DEVEL;
#       }
#
#       # Info about mongodb index
#       $self->_set_last_index($cursor);
#       Log::Loger->info(__PACKAGE__, "[MMSM] MongoDB index: ".$self->get_last_index());

A casy?

PRED VRSTVOU
Time: 0.00
Count_all: 7, time: 1.26
Count_all: 7, millis: 1238

---

ZA VRSTVOU
Count_all: 7, time: 1.27

---

WEB

Viewing duration: 1.8993s

Misto puvodnich:

PRED VRSTVOU
Time: 0.00
Count_all: 7, time: 1.25
Count_all: 7, millis: 1253

---

ZA VRSTVOU
Count_all: 7, time: 6.26

---

WEB

Viewing duration: 6.8893s

Musim to jeste otestovat na ostrem, abych mohl rict, ze to je smerodatne:)

R.

Overeno na ostrem mentat.cesnet.cz, je tam velmi znatelne zrychleni..
Kdyz tak vysvetlim na VC.

$filter = {'Alert.Source.Node.Address.ipv4.min' => { '$gte' => $min}, 'Alert.Source.Node.Address.ipv4.max' => { '$lte' => $max}, 'Alert.Classification.@text' => 'Webattack'};

PRED VRSTVOU
Count_all: 9, time: 2.25
Count_all: 9, millis: 2326
---
ZA VRSTVOU
Count_all: 9, time: 10.85
---
WEB
Viewing duration: 12.4319s
--------------------------
PRED VRSTVOU
Count_all: 9, time: 2.14
Count_all: 9, millis: 2135
---
ZA VRSTVOU
Count_all: 9, time: 2.14
---
WEB
Viewing duration: 3.4621s

------------------------------------------------

$filter = {'Alert.Source.Node.Address.ipv4.min' => { '$gte' => $min}, 'Alert.Source.Node.Address.ipv4.max' => { '$lte' => $max}};

PRED VRSTVOU
Count_all: 1, time: 5.25
Count_all: 1, millis: 5467
---
ZA VRSTVOU
Count_all: 1, time: 24.23
---
WEB
Viewing duration: 26.5013s
--------------------------
PRED VRSTVOU
Count_all: 1, time: 5.64
Count_all: 1, millis: 4956
---
ZA VRSTVOU
Count_all: 1, time: 4.98
---
WEB
Viewing duration: 5.9708s

Pokud to stihneš, tak možná Radku také zkus poštvat profilér i na ty svoje testovací skripty a vlož jsem zase svůj výsledek, ať máme na VC nad čím podumat...divné totiž je, že jednak máme neskutečně odlišné výstupy a druhak mě to v databázi nic nenašlo a tobě koukám že jo.

Delal jsi odlisne mereni nez ja.
Po prekontrolovani a predelani jsem to sjednotil a vysledky mame srovnatelne..

ZA VRSTVOU
Count_all: 1, time: 14.48

DURATION: 14.9935939311981, COUNT: 1

Meku sorry, ale venoval jsem tomu dost casu (nemyslim to zle) a dneska navic nestiham, vystupu profilovani moc nerozumim, domluvme se, prosim, az na VC.

Jen abychom to nikde nehledali, tak tady je návod jak pustit libovolný dotaz v mongo shellu ze skriptu, tak, aby se vypsal kurzor a zároveň u toho změřit čas:

Příklad testovacího skriptu test.js:

db.alerts.find({"Alert.Source.Node.Address.ipv4.min":{ $gte : HexData(0,"9EC49E00")}, "Alert.Source.Node.Address.ipv4.max" : { $lte : HexData(0,"9EC49EFF")}}).limit(30).sort({"Alert.DetectTime.@ntpstamp":-1}).toArray();

Pak samotné měření:

root@mentat:~# more test.js
root@mentat:~# time mongo mentat test.js

Pro deterministicke testovani jsem udelal dva skripty. Je to pushnuto do devel kodu a delal i testoval jsem to na mentat-dev.

prototypes/Mongodb.pm
prototypes/Mongodb.pl

Mongodb shell - Prime volani javascriptoveho kodu pres mongoshell:

($limit, $skip, $sort) = (30, 0, {'Alert.DetectTime.@ntpstamp' => -1});
$shell = 'function shell () { var a = db.alerts.find({"Alert.Source.Node.Address.ipv4.min" : {$gte : HexData(0,"B78E8800")},
"Alert.Source.Node.Address.ipv4.max" : {$lte : HexData(0, "B78E88FF")}, "Alert.Classification.@text" :
"Portscan"}).limit('.$limit.').skip('.$skip.').sort({"Alert.DetectTime.@ntpstamp" : -1}).toArray(); return a.length; };';

my $count = `echo '$shell' | mongo --quiet mentat`;

Mongodb shell
Time: 1.50 s

Perl find - Volani pres perl mongodb driver

($limit, $skip, $sort) = (30, 0, {'Alert.DetectTime.@ntpstamp' => -1});
$filter = {'Alert.Source.Node.Address.ipv4.min' => { '$gte' => $min}, 'Alert.Source.Node.Address.ipv4.max' => { '$lte' => $max},
'Alert.Classification.@text' => 'Portscan'};
@query = (Tie::IxHash->new(%$filter), { limit => $limit, skip => $skip, sort_by => $sort});

my $client = MongoDB::MongoClient->new(host => 'localhost', port => 27017);
my $database = $client->get_database('mentat');
my $collection = $database->get_collection('alerts');
my $result = $collection->query(@$query);

Perl find
Time: 1.46 s

Perl eval - Volani pres perl mongodb driver, ale predan javascriptovy kod (obdoba volani pres shell) - $query je identicke viz shell nahore.

($limit, $skip, $sort) = (30, 0, {'Alert.DetectTime.@ntpstamp' => -1});
my $client = MongoDB::MongoClient->new(host => 'localhost', port => 27017);
my $database = $client->get_database('mentat');
my $count = $database->eval($query);

Perl eval
Time: 1.48 s

Mentat storage - Volani pres nas mongodb storage find (jen pro srovnani)

Mentat storage
Time: 3.56 s

Mentat message - Volani pres nas mongodb storage message find_msg (zpracuje objekty) - jen pro srovnani

Mentat message
Time: 3.60 s

Dotaz XYZ

($limit, $skip, $sort) = (30, 100, {'Alert.DetectTime.@ntpstamp' => -1});

Mongodb shell
Time: 0.64

Perl find
Time: 0.56

Perl eval
Time: 0.58

Mentat storage
Time: 2.81

Mentat message
Time: 2.83

Dotaz XYZ - (Ukol od Pavla Mekovi: explain jen když je povolená konzole)

lib/Mentat/Storage/Mongo.pm
#$self->_set_last_index($cursor);
#Log::Loger->info(__PACKAGE__, "[MMSM] MongoDB index:".$self->get_last_index());

Mongodb shell
Time: 0.65 (stejne)

Perl find
Time: 0.57 (stejne)

Perl eval
Time: 0.56 (stejne)

Mentat storage (o 1.7 s rychlejsi)
Time: 1.11

Mentat message (o 1.7 s rychlejsi)
Time: 1.13

Dotaz XYZ - (JEN pro srovnani, ze nase mezivrstva je stejne rychla i se zpracovanim dat, jako dotaz pres shell).
Nikde ve skriptu totiz nenacitam count z kurzoru.

lib/Mentat/Storage/Mongo.pm
#my $count = $cursor->count();
my $count = 30;
#$self->_set_last_index($cursor);
#Log::Loger->info(__PACKAGE__, "[MMSM] MongoDB index:".$self->get_last_index());

Mongodb shell
Time: 0.63

Perl find
Time: 0.56

Perl eval
Time: 0.56

Mentat storage
Time: 0.57

Mentat message
Time: 0.58

V mailu jsem zapomnel napsat, ze pro kazdy dotaz / u kazdeho mereni jsem znovu vytvarel a navazoval spojeni s databazi. Myslim si, ze je to spravna myslenka, ze pri volani Mongo shellu musi byt znovu navazano spojeni - proto jsem chtel i pro perl find vzdy znovu navazat spojeni.

Na zaklade meho mereni dochazim k zaveru, ze nami vyuzivane a pozadovane funkce (limit, skip, sort) jsou srovnatelne rychle ve vsech merenich - testovano volani pres mongo shell, bezne volani pres perl mongodb api, javascript pres perl mongodb api, nase vrstvy/nadstavby (storage, storage-message). Meka zajimalo, jestli je perlove api pro pristup k Mongodb srovnatelne rychle jako mongo shell - podle mych mereni - ANO je - viz Dotaz XYZ.

V nasi mentat nadstavbe se pouzivaji dve veci, ktere nemam zahrnuty v mereni - count, eval (zjisteni vyuzivani indexu). Pokud tato dve mista do testovani nezahrnuji, je rychlost prakticky totozna, opet viz Dotaz XYZ.

• velmi dlouhe dotazy (nad 1 minutu)
• jestli nase zpracovani v mentat nadstavbe pridava nejakou rezii (testoval jsem vse pouze s limitem 30) - zkusim to s limity 1000, 10000, 100000.
• otestuji muj skript a mereni na ostre databazi mentat.

Ze zapisu #1658 jeste zbyva:

Nereseno:
- postupné nebo kompletní vyčítání výsledků? (asi cursor→next vs cursor→all)
Nedoreseno
- změní výkon pokud si řekneme jen o sloupce, které chceme, vs když
čteme celé zprávy

Test rychlosti dotazu, pokud si rekneme jen o nektere zaznamy/"sloupce".

Rychlost jsem testoval skriptem, pro lepsi meritelnost a vzdy jsem si zapsal nejrychlejsi vysledek (3x spusteno se stejnymi vstupnimi parametry). Testovano pomoci cisteho perl mongodb api - find (limit, skip, fields). Vystup jsem si overoval vypsanim vzdy jednoho zaznamu pomoci print Dumper($_);

$result->sort({'Alert.DetectTime.@ntpstamp' => -1});
$result->skip(1000);
$result->limit(X);

BEZ fields (bez omezeni "sloupcu").
-------------------------------
$result->limit(100000);
time: 6.16

$result->limit(10000);
time: 0.63

$result->limit(1000);
time: 0.07

Bez idmef zpravy
----------------
->fields({
        'msg_raw' => 0,
})

$result->limit(100000);
time: 5.41

$result->limit(10000);
time: 0.56

$result->limit(1000);
time: 0.07

Pouze _id a parametry pouzivane pro vypsani v ALERTS
----------------------------------------------------
$result->sort({'Alert.DetectTime.@ntpstamp' => -1});
$result->skip(1000);
->fields({
        'Alert.Source.Node.Address.ipv4.ip' => 1,
        'Alert.Source.Node.Address.ipv4.max' => 1,
        'Alert.Source.Node.Address.ipv4.min' => 1,
        'Alert.Target.Node.Address.ipv4.ip' => 1,
        'Alert.Target.Node.Address.ipv4.max' => 1,
        'Alert.Target.Node.Address.ipv4.min' => 1,
        'Alert.Classification.@text' => 1,
        'Alert.DetectTime.@ntpstamp' => 1
})

$result->limit(100000);
time: 3.33

$result->limit(10000);
time: 0.35

$result->limit(1000);
time: 0.06

Moje shrnuti je takove, ze pokud bychom vypisovali a zpracovavali desetisicice zaznamu pro vystup, pak to smysl ma. Napr. pro dotaz, ktery je schopen realne vratit 100 000 zaznamu se zpracovanim na databazove urovni usetrilo zhruba 3s - (6.16s ; 5.41s bez msg_raw ; 3.33s pouze 5 sloupcu).