Wraz z udostępnieniem Solr 8.5.0 dostaliśmy możliwość bardzo łatwego indeksowania logów, które Solr produkuje. Posiadając te dane w samym Solr jesteśmy w stanie je przeszukiwać i analizować z wykorzystaniem facetingu. Zobaczmy zatem jak skorzystać z tego narzędzia.
Założenia
W ramach naszego prostego testu nie będziemy przygotowywać wymyślnej struktury naszej kolekcji. Skorzystamy z konfiguracji _default dostępnej domyślnie wraz z Solr. Pozwoli to nam na podstawową zabawę. W przypadku kiedy chcielibyśmy skorzystać z nowego narzędzia w środowisku produkcyjnym zalecamy jednak przygotowanie odpowiedniej struktury.
Środowisko testów
Środowisko naszych testów jest proste. Uruchamiamy Solr za pomocą następującego polecenia:
$ bin/solr start -c -f
Następnie tworzymy kolekcję o nazwie test oraz kolekcję o nazwie logs. Tą pierwszą wykorzystamy do zadania kilku zapytań, a ta druga będzie służyć do zaindeksowania logów. Kolekcje tworzymy za pomocą następujących poleceń:
$ bin/solr create_collection -c test
$ bin/solr create_collection -c logs
Dodatkowo potrzebujemy danych:
$ curl -H 'Content-type:application/json' -XPOST 'localhost:8983/solr/test/update?commit=true' -d '[
{
"id": 1,
"title": "Test document one"
},
{
"id": 2,
"title": "Test document two"
}
]'
Na sam koniec możemy zadać kilka zapytań:
$ curl -XGET 'localhost:8983/solr/test/select?q=*:*'
$ curl -XGET 'localhost:8983/solr/test/select?q=*:*&fq=id:1'
Indeksowanie logów
Do moich testów Solr zainstalowany był w katalogu /opt/solr, a same logi dostępne w katalogu /opt/solr/server/logs. Biorąc to pod uwagę wysłanie wszystkich logów z tego katalogu do kolekcji logs naszego lokalnego Solr jest bardzo proste i wymaga następującego polecenia:
$ bin/postlogs http://localhost:8983/solr/logs /opt/solr/server/logs/
Krótka chwila oczekiwania i powinniśmy zobaczyć następujący komunikat:
Sending last batch ...
Committed
Nasze logi gotowe są do wyszukiwania i analizy.
Wyszukiwanie w logach
Zobaczmy zatem co w logach piszczy. Najprostszy sposób wyszukiwania to po prostu zadanie zapytanie o wszystkie dokumenty, czyli tzw. match all:
http://localhost:8983/solr/logs/select?q=*:*
Odpowiedź od Solr jest następująca:
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":0,
"params":{
"q":"*:*"}},
"response":{"numFound":23,"start":0,"docs":[
{
"date_dt":"2020-03-28T11:25:52.506Z",
"qtime_i":33,
"status_s":"0",
"params_t":"wt=json",
"wt_s":"json",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/info/system",
"type_s":"admin",
"id":"673b31e1-4e7f-4add-8f11-21094a20a790",
"file_s":"solr.log",
"_version_":1662407100088713216},
{
"date_dt":"2020-03-28T11:25:52.542Z",
"qtime_i":2,
"status_s":"0",
"params_t":"action=CLUSTERSTATUS&wt=json",
"wt_s":"json",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/collections",
"type_s":"admin",
"id":"a14d72a3-3a08-406e-bbb8-455743b770ea",
"file_s":"solr.log",
"_version_":1662407100099198976},
{
"date_dt":"2020-03-28T11:25:52.749Z",
"qtime_i":0,
"status_s":"0",
"params_t":"action=list&wt=json",
"wt_s":"json",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/collections",
"type_s":"admin",
"id":"12141bf6-6a46-49f6-9cc9-72a037755771",
"file_s":"solr.log",
"_version_":1662407100100247552},
{
"date_dt":"2020-03-28T11:25:54.645Z",
"core_s":"test_shard1_replica_n1",
"type_s":"newSearcher",
"line_t":"2020-03-28 11:25:54.645 INFO (searcherExecutor-14-thread-1-processing-n:192.168.1.197:8983_solr x:test_shard1_replica_n1 c:test s:shard1 r:core_node2) [c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [test_shard1_replica_n1] Registered new searcher Searcher@7b44e20e[test_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}",
"id":"66b4a193-17de-46fb-a586-d3359c20af0b",
"file_s":"solr.log",
"_version_":1662407100101296128},
{
"date_dt":"2020-03-28T11:25:54.795Z",
"qtime_i":1624,
"status_s":"0",
"params_t":"qt=/admin/cores&coreNodeName=core_node2&collection.configName=test&newCollection=true&name=test_shard1_replica_n1&action=CREATE&numShards=1&collection=test&shard=shard1&wt=javabin&version=2&replicaType=NRT",
"wt_s":"javabin",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"collection_s":"test",
"core_s":"test_shard1_replica_n1",
"shard_s":"shard1",
"replica_s":"core_node2",
"path_s":"/admin/cores",
"type_s":"admin",
"id":"31db40d4-9273-47d6-af6e-98665b2b0bb6",
"file_s":"solr.log",
"_version_":1662407100102344704},
{
"date_dt":"2020-03-28T11:25:54.899Z",
"qtime_i":2146,
"status_s":"0",
"params_t":"replicationFactor=1&maxShardsPerNode=-1&collection.configName=test&name=test&action=CREATE&numShards=1&wt=json",
"wt_s":"json",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/collections",
"type_s":"admin",
"id":"51a735fc-fc90-49b6-ae13-2823a708c287",
"file_s":"solr.log",
"_version_":1662407100103393280},
{
"date_dt":"2020-03-28T11:26:20.675Z",
"qtime_i":2,
"status_s":"0",
"params_t":"wt=javabin&version=2&key=solr.core.test.shard1.replica_n1:QUERY./select.requests&key=solr.core.test.shard1.replica_n1:UPDATE./update.requests&key=solr.core.test.shard1.replica_n1:INDEX.sizeInBytes",
"wt_s":"javabin",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/metrics",
"type_s":"admin",
"id":"17928b68-4a83-41e9-84b2-15533028c0c4",
"file_s":"solr.log",
"_version_":1662407100104441856},
{
"date_dt":"2020-03-28T11:26:20.683Z",
"qtime_i":1,
"status_s":"0",
"params_t":"wt=javabin&version=2&key=solr.jvm:os.processCpuLoad&key=solr.node:CONTAINER.fs.coreRoot.usableSpace&key=solr.jvm:os.systemLoadAverage&key=solr.jvm:memory.heap.used",
"wt_s":"javabin",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"path_s":"/admin/metrics",
"type_s":"admin",
"id":"a8cd34ff-4a13-4d6e-a59a-21b882aacd19",
"file_s":"solr.log",
"_version_":1662407100105490432},
{
"date_dt":"2020-03-28T11:27:10.751Z",
"type_s":"commit",
"line_t":"2020-03-28 11:27:10.751 INFO (qtp776700275-20) [c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1662406970049560576,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}",
"soft_commit_s":"false",
"open_searcher_s":"true",
"collection_s":"test",
"core_s":"test_shard1_replica_n1",
"shard_s":"shard1",
"replica_s":"core_node2",
"id":"11eacb14-ba19-4fcf-bf37-e13e75b58a17",
"file_s":"solr.log",
"_version_":1662407100106539008},
{
"date_dt":"2020-03-28T11:27:10.888Z",
"core_s":"test_shard1_replica_n1",
"type_s":"newSearcher",
"line_t":"2020-03-28 11:27:10.888 INFO (searcherExecutor-14-thread-1-processing-n:192.168.1.197:8983_solr x:test_shard1_replica_n1 c:test s:shard1 r:core_node2) [c:test s:shard1 r:core_node2 x:test_shard1_replica_n1] o.a.s.c.SolrCore [test_shard1_replica_n1] Registered new searcher Searcher@404ea7b6[test_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.5.0):C2:[diagnostics={os=Mac OS X, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=8.5.0, os.arch=x86_64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=10.15.4, timestamp=1585394830809}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}",
"id":"6a0a6fe0-7390-49c8-921d-e269f14de12f",
"file_s":"solr.log",
"_version_":1662407100107587584}]
}}
Oczywiście należy pamiętać, iż korzystamy z konfiguracji _default, ale już w tym momencie widać kilka ciekawych informacji, które dostępne są w odpowiednich polach:
- czas wystąpienia zdarzenia dostępny w polu date_dt
- czas trwania zapytania w polu qtime_i
- parametry zapytania w polu params_s
- nazwa kolekcji w polu collection_s
- shard oraz core w polach shard_s i core_s
Znając nazwy pól możemy np. poprosić o wszystkie żądania do handlera /select i zobaczyć jakie kolekcje były używane oraz np. sprawdzić, czy były zapytania wykonujące się pomiędzy 0, a 100ms oraz powyżej 100ms:
http://localhost:8983/solr/logs/select?q=path_s:\/select&facet=true&facet.field=collection_s&facet.interval=qtime_i&&facet.interval.set=[0,100)&facet.interval.set=[100,*]
Odpowiedź Solr w tym wypadku byłaby następująca:
{
"responseHeader":{
"zkConnected":true,
"status":0,
"QTime":0,
"params":{
"q":"path_s:\\/select",
"facet.field":"collection_s",
"facet.interval":"qtime_i",
"facet":"true",
"facet.interval.set":["[0,100)",
"[100,*]"]}},
"response":{"numFound":2,"start":0,"docs":[
{
"date_dt":"2020-03-28T11:27:39.401Z",
"qtime_i":51,
"status_s":"0",
"hits_l":2,
"params_t":"q=*:*",
"q_s":"*:*",
"q_t":"*:*",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"collection_s":"test",
"core_s":"test_shard1_replica_n1",
"shard_s":"shard1",
"replica_s":"core_node2",
"path_s":"/select",
"type_s":"query",
"id":"3af60e9f-85cf-4958-89c5-b239e80af179",
"file_s":"solr.log",
"_version_":1662407100112830464},
{
"date_dt":"2020-03-28T11:27:52.597Z",
"qtime_i":11,
"status_s":"0",
"hits_l":1,
"params_t":"q=*:*&fq=id:1",
"q_s":"*:*",
"q_t":"*:*",
"distrib_s":"true",
"shards_s":"false",
"ids_s":"false",
"collection_s":"test",
"core_s":"test_shard1_replica_n1",
"shard_s":"shard1",
"replica_s":"core_node2",
"path_s":"/select",
"type_s":"query",
"id":"c6190ce0-845b-4fe8-b646-e5fc3d69bc80",
"file_s":"solr.log",
"_version_":1662407100113879040}]
},
"facet_counts":{
"facet_queries":{},
"facet_fields":{
"collection_s":[
"test",2,
"logs",0]},
"facet_ranges":{},
"facet_intervals":{
"qtime_i":{
"[0,100)":2,
"[100,*]":0}},
"facet_heatmaps":{}}}
Dwa zapytania, wszystkie do kolekcji test, wszystkie w przedziale od 0 do 100ms.
Podsumowanie
Narzędzie bin/postlogs jest moim zdaniem dobrym krokiem w kierunku łatwego i szybkiego indeksowania logów w przypadku kiedy chcemy skorzystać z możliwości analizy i wyszukiwania danych Solr. Indeksując dane zyskujemy możliwość wykorzystania nie tylko wyszukiwania pełnotekstowego, ale także skorzystania z facetingu, czyli analizy danych. Oczywiście, aby korzystać z tego rozwiązania w środowisku produkcyjnym i traktować je jako element na którym możemy polegać w przypadku awarii konieczne byłoby indeksowanie danych co pewien interwał czasu oraz utrzymywanie oddzielnego klastra Solr do samych logów. Ale to już temat na inny wpis 🙂