search

clarat-org / clarat

An Open Source Charity Directory
http://www.clarat.org/
MIT License
8 stars 10 forks source link

Performance im Backend (Suche) #1409

Open NilsVollmer opened 6 years ago

NilsVollmer commented 6 years ago

Die Researcher berichten immer mal wieder von schlechter Performance im Backend und in den Logs kann man das auch immer sehr gut an den vielen High Response Time / Timeout (30 sekunden) Errors sehen.

Ich konnte jetzt keinen Fehler in den Logs finden und ich vermute, dass das Problem mit der Suche zusammenhängt: sowohl bei den Filtern als auch bei der Freitextsuche (pg_search) schicken wir direkt bei jedem Tastaturanschlag eine neue Suche ab. Gerade pg_search auf großen Modellen, wie Offer etc. wird von der Performance eher ein paar Sekunden brauchen. Der Nutzer tippt aber natürlich einfach weiter und erstellt so sehr viele Queries auf einmal. Beispiel aus den Logs:

17 Oct 2017 08:43:37.831359 <158>1 2017-10-17T06:43:37.468518+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20" host=claradmin.herokuapp.com request_id=78c5e37b-4dc2-444e-b225-8ca7cfbff5e0 fwd="83.236.189.194" dyno=web.1 connect=3ms service=30000ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:43:44.245360 <158>1 2017-10-17T06:43:43.564523+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20w" host=claradmin.herokuapp.com request_id=5e0f92ad-fecf-42a1-a4b4-6cca29d1105a fwd="83.236.189.194" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:43:47.998361 <158>1 2017-10-17T06:43:47.610466+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20wo" host=claradmin.herokuapp.com request_id=4df2907c-9ca8-4654-8a1a-47e25a41a5a9 fwd="83.236.189.194" dyno=web.1 connect=0ms service=30000ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:43:51.955362 <158>1 2017-10-17T06:43:51.292202+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20woh" host=claradmin.herokuapp.com request_id=79e88005-eace-443b-8d75-0d8b6b46ed65 fwd="83.236.189.194" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:43:56.923363 <158>1 2017-10-17T06:43:56.196944+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20wohn" host=claradmin.herokuapp.com request_id=25107ecf-8cc1-4a16-b710-ca9dfe6b0f56 fwd="83.236.189.194" dyno=web.1 connect=0ms service=30000ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:44:03.240364 <158>1 2017-10-17T06:44:02.555120+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20wohng" host=claradmin.herokuapp.com request_id=5aa38348-ede2-437e-90c5-484aafe1c84a fwd="83.236.189.194" dyno=web.1 connect=1ms service=30000ms status=503 bytes=0 protocol=httpCriticalHigh Response Time
17 Oct 2017 08:44:22.098368 <158>1 2017-10-17T06:44:21.422190+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20wohngrupp" host=claradmin.herokuapp.com request_id=d3ce110c-b37b-4289-b20f-cc8f1eae53c4 fwd="83.236.189.194" dyno=web.1 connect=0ms service=30001ms status=503 bytes=0 protocol=httpHigh Response TimeCritical
17 Oct 2017 08:44:27.875369 <158>1 2017-10-17T06:44:26.336256+00:00 heroku router - - at=error code=H12 desc="Request timeout" method=GET path="/api/v1/offers?query=betreute%20wohngruppe" host=claradmin.herokuapp.com request_id=aab641e8-844a-4334-a1d1-aa2f023fa01f fwd="83.236.189.194" dyno=web.1 connect=0ms service=30000ms status=503 bytes=0 protocol=httpHigh Response TimeCritical

In diesen Fällen wär die Last auf dem Server deutlich geringer, wenn nur am Ende eine finale Query abgeschickt werden würde anstatt n queries für jeden Tastaturanschlag. Wir sollten also entweder einen 'Abschicken/Filtern/Suchen'-Button einbauen oder einen Timer laufen lassen, der immer zurückgesetzt wird, wenn eine neue Taste angeschlagen wird und erst wenn dann 2-3 Sekunden nichts neues getippt wurde, wird die Suche abgeschickt.

@Twiek Bitte priorisieren ;)

KonstantinKo commented 6 years ago

Erster Quick-Fix ist deployed: Bei der Freitext-Suche und in den FilteringSelect-Auswahlfeldern läuft ein 400ms timeout nach jeden Tastenanschlag ab, nach dem erst die Suchanfrage abgefeuert wird. Beim schnelleren Tippen sollte also nicht für jeden neuen character ein request erfolgen.

Außerdem habe ich den Bug gefixt, nach dem der loading-state von Index-Tabellen nicht mehr angezeigt wurde (Tabelle wird durchsichtig solange geladen wird).

Weitere Fehlerbehebung (v.A. in filtern) wird durch das filter-refactoring durch @NilsVollmer blockiert.