Zoekindex Lucene verder geoptimaliseerd

Meresco, onze library van search en retrieval software, gebruikt Lucene voor de zoekindex. Lucene is ontwikkeld in Java; onze code is geschreven in Python. Python biedt verschillende mogelijkheden om deze Java code te gebruiken. De open source Software Foundation Apache biedt de mogelijkheid de Java code beschikbaar te maken binnen Python. Dit kan met PyLucene (http://lucene.apache.org/pylucene/).

Opvallend

Tot voor kort maakte we alleen maar gebruik van PyLucene om onze indexen aan te spreken. Op onze software draait continu een monitoring systeem, dat ons inzicht geeft in performance. We merkten steeds vaker dat er geheugen ‘kwijt’ was. Een ander opvallend fenomeen was dat het nodig werd de indexen eens in de zoveel tijd te herstarten, omdat deze anders ‘Out of memory’ gingen. Duidelijk: er was iets aan de hand, en we doken erin. Ondanks veel memory profiling en het bekijken van heap-dumps, die laten zien waaruit het gebruikte geheugen was opgebouwd, kwamen we niet tot een bevredigende conclusie waarom de garbage collector zijn werkt niet goed deed. Java objecten, waarvan wij zagen dat die wel konden worden opgeruimd, werden níet opgeruimd.

Zagen wij iets over het hoofd? Hadden we echt een geheugenlek? Of had de garbage collector te veel te doen om dit binnen de gewenste tijden op te kunnen ruimen?

Aankijken

Ondertussen bleven onze indexen groeien, alsook het aantal queries aan de indexen. Tot we uiteindelijk voor sommige indexen meerdere keren per dag een ‘out of memory error’-melding kregen. Om wat ruimte te scheppen, zetten we het automatisch bijwerken van de indexen daarom uit, en voerden we die handmatig uit op rustige momenten van de dag. Dit gaf voorlopig ruimte, maar dat is geen duurzame oplossing. Tijd voor actie dus.

Actie

Wij hebben een tijdje gebruik gemaakt van het open source enterprise search platform Solr, dat in Java is geschreven. Solr maakt gebruik van de zoekindex-functionaliteit van Lucene, en biedt een http-service aan om queries te stellen. Wat zou er gebeuren als wij ook deze strategie zouden volgen? We zouden Lucene in Java gaan draaien, de ‘native’ taal. Het combineren van garbage in Python en Java komt dan niet meer voor en lost eventuele problemen die we daarmee hebben op. We waren ook heel benieuwd wat er met de performance zou gebeuren.

We schreven onze eigen code om naar Java, bovenop Lucene, en plaatsten er een http-service voor. Na een aantal dagen Java code schrijven, met in het achterhoofd dat het ons zowiezo zou helpen bij het vinden van een oplossing, lukte het ons om weer een werkende versie te krijgen.

Performance testen

De code installeerden we op een acceptatie server met veel data. De eerste testresultaten waren erg bemoedigend. Ze gaven aan dat de indexen zelfs meer dan dubbel zo snel waren geworden. Dat was een beter resultaat dan we verwacht hadden. Maar de grote vraag: is ons geheugenprobleem opgelost, was nog niet beantwoord. We lieten daarom een duurtest los op de oplossing. We bestookten het systeem urenlang met een continue load, waarvan we wisten dat het oude systeem daar al snel onder zou bezwijken. En jawel: er kwamen geen geheugenproblemen meer voor.

Gemiddelde responstijden voor en na release op 16 december

Gemiddelde responstijden voor en na release (op 16 december 2015)

In de roos

Het leek er sterk op dat we ons probleem opgelost hadden. Ons vermoeden dat het in puur Java beter zou moeten gaan, klopte. Als klap op de vuurpijl kregen we er ook nog een enorme performance verbetering bij.

Uiteindelijk hebben we deze aanpak een tijdje laten meedraaien op de acceptatie-omgeving om er zeker van te zijn dat de werking probleemloos was. Intussen is het alweer een tijdje gereleased naar een productie omgeving, waar het nu vlekkeloos draait.

 

Performance index Lucene

Al lange tijd is de performance van onze index (Lucene) een hot item bij Seecr. De standaard performance van Lucene voor normale query’s en drilldown is prima. Maar over de performance van de join-functionaliteit zijn wij niet tevreden. Daarom zijn we al over gestapt op onze eigen manier van joinen, om de snelheid te kunnen garanderen. (Lees meer hierover in ons eerder verschenen artikel)

Het resultaat van onze eigen code werd vanaf het begin al gecached om het snel en acceptabel te maken. Zodra een gebruiker dezelfde zoekvraag opnieuw stelde stond het resultaat meteen klaar in de cache.

Naarmate we steeds meer records en gebruikers kregen, begonnen er wat problemen te ontstaan. De servers gebruikten meer geheugen en de query’s werden trager.  Een automatische refresh van al onze records instellen, zodat er elke vijf minuten nieuwe records geïndexeerd worden, zou het systeem nog trager maken. Dat kunnen we ons niet permitteren. Ik ben in de code gedoken om te achterhalen waarom het systeem op deze manier reageerde.

Compacter opslaan
Al snel ontdekte ik dat de caches die gemaakt worden voor onze eigen join-code veel geheugen gebruiken. Een goede oplossing hiervoor dacht ik te hebben gevonden in de vorm van compacter opslaan. Het gebruik ging voor één query van 300Mb naar 2Mb; een enorme verbetering. Maar helaas was de oplossing niet zo simpel. Sterker nog, de query’s leken hierdoor om de zoveel tijd nog trager dan dat ze al waren.

Wat bleek nu, het maken van de cache was erg veel duurder geworden. Vandaar dus dat de query’s soms nog trager waren. Tijdens een brainstorm met mijn collega’s werd het idee geopperd om het eens te testen zonder enige vorm van caching. Misschien was het verzamelen van alle gegevens wel zo snel dat het maken van een cache niet opweegt tegen die snelheid.

Dat vond ik het proberen waard. De code heb ik opnieuw geschreven en inderdaad, het verzamelen van alle gegevens was ook erg snel zonder caching. Toch was het niet voldoende om volledig zonder te kunnen.

Minder committen
Tot dit moment werd Lucene eens in de 1000 records of om de 10 seconden gecommit. Binnen maximaal zoveel seconden waren wijzigingen daardoor zichtbaar. Was dit misschien iets te veel van het goede? Zo belangrijk was het niet dat wijzigingen zichtbaar moesten worden. Records worden zelfs maar een paar keer in de zoveel tijd toegevoegd en zeker niet elke 10 seconden.

Daarom hebben we hier verandering in gebracht. We committen nog maar elke 5 minuten of elke 100.000 records. Dit had een positief resultaat; de query’s waren nog maar maximaal eens in de 5 minuten trager. De gebruiker merkte hier dus behoorlijk minder van.

Maar na een tijdje kwamen er klachten dat het systeem vaak traag reageerde. Eens in de 5 minuten committen is toch niet voldoende. Hier moest toch een goede oplossing voor zijn te vinden. Ik heb besloten om over te gaan om een andere vorm van caching. Eén waarin we simpelweg het eindresultaat van de join-query wordt bewaard. Deze vorm gebruikte weinig geheugen, maar moest wel elke keer alles opnieuw berekenen; dit tegenover de oude vorm die alleen het gewijzigde deel opnieuw berekende. Deze nieuwe caches konden dan ook na elke commit opnieuw gemaakt worden.

Nog steeds waren wie hiermee niet waar we wilden zijn. Doordat we zo weinig committen werden de commits uiteraard wat duurder. Tot onze verbazing gebeurde het dat dit tot wel 8 seconden kon duren. Veel te lang als de query daarop moet wachten. En als we onze automatische refresh aanzetten werden er elke vijf minuten records toegevoegd en bereikten we hier dus helemaal niets mee. Nog steeds was het om de 5 minuten veel te traag, ondanks dat we al zoveel geoptimaliseerd hadden. Een behoorlijke tegenvaller.

Multi threading
Het was lastig om ook dit nog op te lossen. We konden geen goede optimalisaties voor Lucene bedenken. Totdat ik ineens bedacht dat Lucene multi-threaded is. Dat ik daar niet eerder aan heb gedacht. Want zolang een record geïndexeerd wordt, kan er niet gezocht worden. Dit merk je uiteraard meteen als een commit 8 seconden duurt. Als ik dat nou eens kon veranderen.

Ons indexeer- en zoekproces heb ik gesplitst naar twee verschillende threads. Eén thread om te indexeren en de andere om te zoeken. Tijdens het indexeren is het nu ook mogelijk om te kunnen zoeken. Ook als de writer-thread 8 seconden staat te committen. Eindelijk leek het erop dat we weer een goede performance hebben behaald.

Dé oplossing
De processen gebruiken weer een normale hoeveelheid geheugen en door middel van ons monitoringsysteem kunnen we zien dat de responsetijden weer acceptabel zijn. In onderstaande grafiek is te zien wat het effect van de laatste verbetering was op onze productieomgeving. Deze grafiek toont de gemiddelde responsetijd. Duidelijk is te zien dat we 22 januari gereleased hebben. Alle hogere pieken, die veroorzaakt werden door die 8 seconden commit tijd, zijn verdwenen. Grafiek

Voor nu ben ik heel tevreden met deze oplossing. Al ben ik wel met een nieuw experiment gestart om te kijken of we hier nog meer uit kunnen halen dan nu al mogelijk is. Je kunt maar beter goed voorbereid zijn op eventuele veranderingen in gebruik.