Právě s koncem loňského roku za námi přišel jeden z našich dlouholetých zákazníků, protože jeden z jejich dlouho existujících PostgreSQL dotazů týkajících se výpočtů geometrie PostGIS byl pro konkrétní hodnoty mnohem pomalejší. Prozkoumali jsme problém a zjistili, jak jej vyřešit; číst dál! To, co jsme našli jako příčinu problému, vás překvapí!
Počáteční pozorování nahlášené naším zákazníkem bylo, že spuštění dotazu zahrnujícího ST_DistanceSpheroid trvalo asi 7 milisekund, když byl požádán o vrácení vzdálenosti na POINT(33.681953 23.155994) na konkrétním sféroidu, ale pokud byl tento bod přesunut do POINT(33.681953 23.1559941) (rozdíl pouze 0.0000001 ), pak to trvalo 0,13 milisekundy. 60krát rychlejší! Co se proboha (další sféroid!) může dít?
Zpočátku jsme nebyli schopni reprodukovat pomalost v našich testovacích prostředích. V našich rukou by oba dotazy fungovaly stejně rychle, bez zpomalení. Prošli jsme konkrétními verzemi používaného softwaru a mysleli jsme si, že může být potřeba aktualizace. Použili jsme verze nahlášené zákazníkem:PostgreSQL 10.11, PostGIS 2.4.4, libproj 4.93. Vrátili jsme se do jeskynních věků přechodem na tyto přesné verze, bez úspěchu.
Nakonec jsme si uvědomili, že zákazník používá Ubuntu 18.04, tak jsme to zkusili... a ejhle, problém se tam reprodukoval. Stačí říci, že jsme využili příležitosti profilovat dotaz v tomto stroji. Máme toto:
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
Blábol, říkáš si. Na tomto profilu je však něco moc zajímavého… a vy musíte ignorovat prvních 26 řádků a zaměřit se na __mul tam linka. Vidíte, že 60,82 % „sebe“ času? (Slyším zvuk realizace vaší mysli). Proč tedy určité body na sféroidu zaberou tolik času a jiné ne? A také proč to v Ubuntu 18.04 trvá dlouho, ale na jiných strojích ne? Proč upgrade PostGIS problém nevyřeší?
Odpověď mi byla navržena, jakmile jsem si uvědomil, co je zřejmé:PostGIS provádí spoustu trigonometrie (sinus, kosinus, tangens atd.) voláním libm funkcí. Při pohledu na seznamy změn glibc jsme našli některé optimalizace v trigonometrických funkcích:pro určité vstupy používají výpočty trigonometrie zkratky, které nelze použít pro jiné vstupy; a takové zkratky byly postupem času optimalizovány. Ve skutečnosti glibc oznamuje pro 2.27 i 2.29 optimalizaci funkcí sinus/kosinus/atd. Zřejmě kdysi dávno existovaly nějaké optimalizace od Intelu, které měly poskytovat velmi přesné výsledky, ale pak si někdo uvědomil, že tvrzení o přesnosti bylo nesprávné, takže glibc zakázal použití těchto optimalizací; později byly tyto věci znovu implementovány jiným, ale opět rychlým způsobem. Nebo něco takového – pro outsidery, jako jsem já, je těžké zjistit přesné podrobnosti.
Měli jsme podezření, že upgrade na novější verzi glibc problém vyřeší a vše ostatní zůstane při starém. Náš zákazník to zkusil a skutečně to byla pravda a byli spokojeni. Nejsme si jisti, které Tyto změny glibc byly zodpovědné, ale jedna věc je jasná:vždy je dobrý nápad spouštět věci na aktuálním softwaru.
Mějte na paměti, že stékající okraje jsou ostré… tak buďte opatrní.