Podobnie jak w zeszłym roku, jeden z naszych długoletnich klientów zgłosił się do nas, ponieważ jedno z ich istniejących od dawna zapytań PostgreSQL dotyczących obliczeń geometrii PostGIS było znacznie wolniejsze dla określonych wartości. Zbadaliśmy problem i dowiedzieliśmy się, jak go rozwiązać; Czytaj! To, co znaleźliśmy jako przyczynę problemu, zaskoczy Cię!
Początkową obserwacją, zgłoszoną przez naszego klienta, było uruchomienie zapytania obejmującego ST_DistanceSpheroid zajęło około 7 milisekund, gdy poproszono o zwrócenie odległości do POINT(33.681953 23.155994) na określonej sferoidzie, ale jeśli ten punkt został przeniesiony do POINT(33.681953 23.1559941) (różnica tylko 0.0000001 ) zajęło to 0,13 milisekundy. 60 razy szybciej! Co u licha (kolejna sferoida!) może się dziać?
Początkowo nie byliśmy w stanie odtworzyć spowolnienia w naszych środowiskach testowych. W naszych rękach oba zapytania wykonałyby się równie szybko, bez spowolnienia. Sięgnęliśmy do konkretnych wersji używanego oprogramowania, myśląc, że może być potrzebna aktualizacja. Wykorzystaliśmy wersje zgłoszone przez klienta:PostgreSQL 10.11, PostGIS 2.4.4, libproj 4.93. Wróciliśmy do wieków jaskiniowych, degradując je do tych dokładnych wersji, bez powodzenia.
W końcu zdaliśmy sobie sprawę, że klient używa Ubuntu 18.04, więc spróbowaliśmy tego… i oto problem się tam powtórzył. Wystarczy powiedzieć, że skorzystaliśmy z możliwości profilowania zapytania w tej maszynie. Mamy to:
Samples: 224K of event 'cpu-clock', Event count (approx.): 56043500000 Children Self Command Shared Object Symbol + 84.86% 0.00% postgres [unknown] [.] 0xffffffffffffffff + 84.59% 0.00% postgres postgres [.] DirectFunctionCall4Coll + 84.58% 0.00% postgres postgis-2.5.so [.] geometry_distance_spheroid + 84.56% 0.00% postgres liblwgeom-2.5.so.0.0.0 [.] lwgeom_distance_spheroid + 84.31% 0.19% postgres libm-2.27.so [.] __sincos + 84.18% 0.00% postgres libm-2.27.so [.] __cos_local (inlined) + 84.13% 0.00% postgres libm-2.27.so [.] cslow2 (inlined) + 84.05% 0.01% postgres libm-2.27.so [.] __mpcos + 83.95% 0.32% postgres libm-2.27.so [.] __c32 + 83.87% 0.00% postgres postgres [.] ExecInterpExpr + 83.75% 0.00% postgres postgres [.] standard_ExecutorRun + 83.75% 0.00% postgres postgres [.] ExecutePlan (inlined) + 83.73% 0.00% postgres postgres [.] ExecProcNode (inlined) + 83.73% 0.00% postgres postgres [.] ExecScan + 83.67% 0.00% postgres postgres [.] ExecProject (inlined) + 83.67% 0.00% postgres postgres [.] ExecEvalExprSwitchContext (inlined) + 83.65% 0.00% postgres postgres [.] _SPI_execute_plan + 83.60% 0.00% postgres postgres [.] _SPI_pquery (inlined) + 83.49% 0.01% postgres plpgsql.so [.] exec_stmts + 83.49% 0.00% postgres plpgsql.so [.] exec_stmt (inlined) + 83.49% 0.00% postgres plpgsql.so [.] exec_stmt_fori (inlined) + 83.48% 0.00% postgres plpgsql.so [.] exec_stmt_perform (inlined) + 83.48% 0.00% postgres plpgsql.so [.] exec_run_select + 83.47% 0.00% postgres postgres [.] SPI_execute_plan_with_paramlist + 81.67% 0.01% postgres liblwgeom-2.5.so.0.0.0 [.] edge_distance_to_point + 81.67% 0.00% postgres liblwgeom-2.5.so.0.0.0 [.] 0x00007f2ce1c2c0e6 + 61.85% 60.82% postgres libm-2.27.so [.] __mul + 54.83% 0.01% postgres liblwgeom-2.5.so.0.0.0 [.] sphere_distance + 27.14% 0.00% postgres plpgsql.so [.] exec_stmt_block + 26.67% 0.01% postgres liblwgeom-2.5.so.0.0.0 [.] geog2cart + 19.24% 0.00% postgres libm-2.27.so [.] ss32 (inlined) + 18.28% 0.00% postgres libm-2.27.so [.] cc32 (inlined) + 12.55% 0.76% postgres libm-2.27.so [.] __sub + 11.46% 11.40% postgres libm-2.27.so [.] sub_magnitudes + 8.15% 4.89% postgres libm-2.27.so [.] __add + 4.94% 0.00% postgres libm-2.27.so [.] add_magnitudes (inlined) + 3.18% 3.16% postgres libm-2.27.so [.] __acr + 2.66% 0.00% postgres libm-2.27.so [.] mcr (inlined) + 1.44% 0.00% postgres liblwgeom-2.5.so.0.0.0 [.] lwgeom_calculate_gbox_geodetic + 1.44% 0.00% postgres liblwgeom-2.5.so.0.0.0 [.] ptarray_calculate_gbox_geodetic
Mówisz, bełkot. Jest jednak coś bardzo ciekawego w tym profilu… i musisz zignorować pierwsze 26 linii i skupić się na __mul linia tam. Widzisz, że 60,82% czasu „własnego”? (Słyszę dźwięk realizacji, który właśnie stworzył twój umysł). Dlaczego więc niektóre punkty na sferoidzie zajmują tyle czasu, a inne nie? A także dlaczego w Ubuntu 18.04 trwa to długo, ale nie na innych maszynach? Dlaczego aktualizacja PostGIS nie rozwiązuje problemu?
Odpowiedź została mi zasugerowana, gdy zdałem sobie sprawę z tego, co było oczywiste:PostGIS wykonuje wiele trygonometrii (sinus, cosinus, tangens itp.), wywołując libm Funkcje. Przeglądając dzienniki zmian glibc, znaleźliśmy pewne optymalizacje w funkcjach trygonometrycznych:w przypadku niektórych danych wejściowych obliczenia trygonometryczne są wykonywane na skróty, których nie można zastosować w przypadku innych danych wejściowych; i takie skróty zostały z czasem zoptymalizowane. Rzeczywiście, glibc ogłasza dla obu wersji 2.27 i 2.29 o optymalizacji funkcji sinus/cosinus/etc. Najwyraźniej kiedyś Intel wprowadził optymalizacje, które miały zapewnić bardzo dokładne wyniki, ale ktoś zdał sobie sprawę, że twierdzenie o dokładności było nieprawidłowe, więc glibc wyłączyło korzystanie z tych optymalizacji; później te rzeczy zostały ponownie zaimplementowane w inny, ale znowu szybki sposób. Albo coś w tym rodzaju — osobom z zewnątrz, takim jak ja, trudno jest ustalić dokładne szczegóły.
Podejrzewaliśmy, że aktualizacja do nowszej wersji glibc rozwiąże problem, pozostawiając wszystko inne bez zmian. Nasz klient tego spróbował i rzeczywiście tak było i byli zadowoleni. Nie jesteśmy do końca pewni, który z tych zmian glibc były odpowiedzialne, ale jedno jest jasne:zawsze dobrym pomysłem jest uruchamianie rzeczy na aktualnym oprogramowaniu.
Pamiętaj, że krwawiące krawędzie są ostre… więc bądź ostrożny.
