Ligesom sidste år sluttede, kom en af vores mangeårige kunder til os, fordi en af deres længe eksisterende PostgreSQL-forespørgsler, der involverede PostGIS-geometriberegninger, var meget langsommere for specifikke værdier. Vi undersøgte problemet og fandt ud af, hvordan vi kunne løse det; Læs videre! Hvad vi fandt som årsag til problemet vil overraske dig!
Den begyndende observation, rapporteret af vores kunde, var at køre en forespørgsel, der involverede ST_DistanceSpheroid tog omkring 7 millisekunder, da de blev bedt om at returnere afstanden til POINT(33.681953 23.155994) på en specifik sfæroid, men hvis det punkt blev flyttet til POINT(33.681953 23.1559941) (en forskel på kun 0.0000001 ) så tog det 0,13 millisekund. 60 gange hurtigere! Hvad i alverden (en anden sfæroid!) kunne der foregå?
I starten var vi ikke i stand til at genskabe langsommeligheden i vores testmiljøer. I vores hænder ville begge forespørgsler fungere lige hurtigt uden afmatning. Vi gravede ned til de specifikke versioner af software i brug og tænkte, at en opdatering kunne være nødvendig. Vi brugte versionerne rapporteret af kunden:PostgreSQL 10.11, PostGIS 2.4.4, libproj 4.93. Vi vendte tilbage til hulens tidsaldre ved at nedgradere til de præcise versioner, uden held.
Til sidst blev vi opmærksomme på, at kunden brugte Ubuntu 18.04, så vi prøvede det … og se, problemet reproducerede sig der. Det er tilstrækkeligt at sige, at vi hoppede på muligheden for at profilere forespørgslen i den maskine. Vi fik dette:
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
Voldsomhed, siger du. Der er dog noget meget mærkeligt ved denne profil … og du er nødt til at ignorere de første 26 linjer og fokusere på __mul linje der. Ser du, at 60,82% af "selv" tid? (Jeg kan høre lyden af erkendelse, dit sind lige har lavet). Så hvorfor tager det så meget tid for visse punkter på sfæroiden og ikke andre? Og hvorfor tager det lang tid i Ubuntu 18.04, men ikke i andre maskiner? Hvorfor løser opgradering af PostGIS ikke problemet?
Svaret blev foreslået mig, da jeg indså, hvad der var indlysende:PostGIS laver en masse trigonometri (sinus, cosinus, tangent osv.) ved at kalde libm funktioner. Ved at se på glibc-ændringsloggene fandt vi nogle optimeringer i trigonometrifunktioner:for visse input tager trigonometriberegninger genveje, der ikke kan tages for andre input; og sådanne genveje er blevet optimeret over tid. Faktisk annoncerer glibc for både 2.27 og 2.29 begge optimeringer i sinus/cosinus/etc-funktioner. Tilsyneladende var der engang nogle optimeringer fra Intel, der skulle give meget nøjagtige resultater, men så indså nogen, at påstanden om nøjagtighed var forkert, så glibc deaktiverede brugen af disse optimeringer; senere blev de ting genimplementeret på en anden, men igen hurtig måde. Eller sådan noget - for udenforstående som mig er det svært at finde ud af de nøjagtige detaljer.
Vi havde mistanke om, at en opgradering til en nyere version af glibc ville løse problemet og lade alt andet være det samme. Vores kunde prøvede det, og det var sandt, og de var glade. Vi er ikke rigtig sikre på hvilke af disse glibc-ændringer var ansvarlige, men én ting er klar:det er altid en god idé at køre ting på opdateret software.
Husk på, at blødende kanter er skarpe … så vær forsigtig derude.