Justo cuando terminaba el año pasado, uno de nuestros clientes más antiguos acudió a nosotros porque una de sus consultas de PostgreSQL de larga data que involucraba cálculos de geometría de PostGIS era mucho más lenta para valores específicos. Investigamos el problema y descubrimos cómo resolverlo; ¡Sigue leyendo! ¡Lo que encontramos como la causa del problema te sorprenderá!
La observación inicial, informada por nuestro cliente, fue que ejecutar una consulta que involucraba ST_DistanceSpheroid tomó alrededor de 7 milisegundos cuando se le pidió que devolviera la distancia a POINT(33.681953 23.155994) en un esferoide específico, pero si ese punto se movió a POINT(33.681953 23.1559941) (una diferencia de solo 0.0000001 ) luego tomó 0.13 milisegundos. ¡60 veces más rápido! ¿Qué diablos (¡otro esferoide!) podría estar pasando?
Inicialmente, no pudimos reproducir la lentitud en nuestros entornos de prueba. En nuestras manos, ambas consultas se ejecutarían con la misma rapidez, sin ralentización. Buscamos las versiones específicas del software en uso pensando que podría ser necesaria una actualización. Usamos las versiones reportadas por el cliente:PostgreSQL 10.11, PostGIS 2.4.4, libproj 4.93. Regresamos a la edad de las cavernas al degradar a esas versiones precisas, sin éxito.
Eventualmente nos dimos cuenta de que el cliente estaba usando Ubuntu 18.04, así que lo intentamos... y he aquí que el problema se reprodujo allí. Basta con decir que aprovechamos la oportunidad de perfilar la consulta en esa máquina. Tenemos esto:
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
Un galimatías, dices. Sin embargo, hay algo muy curioso en este perfil... y tienes que ignorar las primeras 26 líneas y concentrarte en el __mul línea allí. ¿Ves ese 60,82% del tiempo "para uno mismo"? (Puedo escuchar el sonido de realización que tu mente acaba de hacer). Entonces, ¿por qué se tarda tanto en ciertos puntos del esferoide y en otros no? ¿Y también por qué tarda mucho en Ubuntu 18.04 pero no en otras máquinas? ¿Por qué la actualización de PostGIS no soluciona el problema?
La respuesta me fue sugerida una vez que me di cuenta de lo que era obvio:PostGIS hace mucha trigonometría (seno, coseno, tangente, etc.) llamando a libm funciones Mirando los registros de cambios de glibc, encontramos algunas optimizaciones en las funciones de trigonometría:para ciertas entradas, los cálculos de trigonometría toman atajos que no se pueden tomar para otras entradas; y tales atajos se han optimizado con el tiempo. De hecho, los anuncios de glibc tanto para 2.27 como para 2.29 mencionan optimizaciones en funciones seno/coseno/etc. Aparentemente, hubo una vez algunas optimizaciones de Intel que se suponía que debían proporcionar resultados muy precisos, pero luego alguien se dio cuenta de que la afirmación de precisión era incorrecta, por lo que glibc deshabilitó el uso de esas optimizaciones; más tarde, esas cosas se volvieron a implementar de una manera diferente pero nuevamente rápida. O algo así:para personas externas como yo, es difícil averiguar los detalles exactos.
Sospechábamos que actualizar a una versión más nueva de glibc solucionaría el problema, dejando todo lo demás igual. Nuestro cliente probó eso, y de hecho era cierto, y estaban felices. No estamos realmente seguros de cuál de estos cambios en la glibc fueron los responsables, pero una cosa está clara:siempre es una buena idea ejecutar las cosas en un software actualizado.
Tenga en cuenta que los bordes sangrantes son afilados... así que tenga cuidado.
