Por qué una consulta de Weaviate va lenta: perfilado por etapas

Oír que una consulta va lenta no le dice casi nada a un ingeniero. Es un parte de síntomas. ¿Lenta respecto a qué referencia, y en qué paso? ¿El filtro de metadatos, el índice vectorial, las lecturas de disco que recuperan los objetos del resultado o la puntuación por palabras clave? Mientras el tiempo no se atribuya a una de esas etapas, cada cambio es un tiro a ciegas: añadir memoria, ajustar ef, bajar el limit. A veces alguno ayuda, casi nunca, y la causa real sigue sin conocerse.

Weaviate acaba de lanzar una función dirigida justo a ese punto ciego. Query Profiling informa, etapa por etapa, en qué gastó el tiempo una consulta lenta concreta.

Por qué no basta con el registro de consultas lentas

El registro de consultas lentas existe en Weaviate desde hace tiempo. Se definen dos variables de entorno, se reinicia el nodo y cualquier consulta que supere un umbral de tiempo acaba en los logs con detalles de tiempos. Para un propósito encaja bien: detectar en silencio regresiones en toda la flota a lo largo de semanas y meses.

Es una mala herramienta para el momento más habitual, cuando una consulta concreta va lenta ahora mismo y la causa hace falta ya. Destacan cuatro carencias:

• Exige un reinicio, y reiniciar un nodo vacía la caché de páginas del sistema operativo. Las primeras consultas después leen datos fríos del disco, así que la medición acaba reflejando el reinicio y no la consulta.
• Funciona a posteriori. Una entrada solo aparece cuando la consulta ya ha ido lenta, así que no se puede apuntar a la que tienes delante. La única opción es esperar a que vuelva a ir lenta.
• El registro se hace por nodo. Una sola consulta se reparte entre shards de varias máquinas, y cada máquina registra solo su parte, con lo que la imagen completa hay que reconstruirla a mano.
• Es un interruptor temporal que hay que recordar y deshacer. Como vive fuera de la configuración del despliegue, tiende a desincronizarse.

Perfilado por consulta

El perfilado de consultas invierte el modelo. En lugar de un ajuste global que espera a que haya problemas, cada petición lo activa de forma individual y el desglose de tiempos vuelve junto con la respuesta. Sin variables de entorno, sin reinicio, sin umbral y sin nada que limpiar después.

En Python basta con importar la clase de metadatos.

from weaviate.classes.query import MetadataQuery

Y con un flag en la propia consulta.

response = collection.query.near_vector(
    near_vector=[0.1, 0.2, 0.3],
    limit=10,
    return_metadata=MetadataQuery(query_profile=True),
)for shard in response.query_profile.shards:
    print(shard.name, shard.node, shard.searches)

El nodo coordinador reúne los perfiles de todos los shards de todos los nodos que participaron y los devuelve juntos, así que una sola petición ofrece una vista de todo el clúster.

Lo admiten los clientes oficiales de Python, JavaScript y TypeScript, Java (v6) y C#, además de gRPC directo. La función pasó a estar disponible de forma general en Weaviate v1.38. Con el flag desactivado, el coste es una comprobación booleana; activado, el motor añade lecturas de temporizadores que cuestan microsegundos. Está pensado para depurar, así que mantenlo fuera de la ruta crítica de producción.

Cómo leer el perfil

Los resultados se agrupan por shard y se omiten las etapas que no se ejecutaron. Por eso una búsqueda vectorial simple produce un perfil distinto al de una búsqueda BM25, y las consultas híbridas incluyen secciones de ambas. Estos son los campos que conviene conocer:

• total_took es el tiempo real de la búsqueda en ese shard, y todas las demás cifras explican una parte.
• objects_took mide la lectura de los objetos finales desde el disco, un paso llamado hidratación. Un valor alto indica una consulta limitada por disco; revisa la caché de páginas, el limit y el tamaño del payload.
• filters_build_allow_list_took junto con filters_ids_matched muestran cuánto tardó la cláusula where en convertirse en una lista de IDs que cumplen la condición, y el tamaño de esa lista. Una lista enorme significa que el filtro es demasiado amplio; una lista corta que aun así tardó mucho apunta a lecturas lentas del índice invertido en disco.
• vector_search_took y knn_search_layer_0_took describen el recorrido de HNSW. Como el grafo vive en RAM, un número alto aquí significa trabajo de CPU, no de disco. Ajusta ef, la dimensionalidad de los vectores y la estrategia de filtrado antes de pedir más hardware.
• knn_search_rescore_took solo aparece con la compresión activada. Vuelve a leer vectores de precisión completa para repuntuar a los candidatos comprimidos, y esa lectura puede llegar al disco.
• kwd_3_term_time y kwd_4_bmw_time son los dos temporizadores de palabras clave que conviene recordar. El primero cubre la lectura de las listas de postings de cada término y depende del número de términos y de la velocidad del disco. El segundo es la puntuación BlockMax WAND, que crece con listas de postings largas y poca selectividad.

Tres perfiles, tres soluciones distintas

Primer caso: un shard con un total algo por debajo de 50 ms.

total_took: 48.2ms
vector_search_took: 8.4ms
filters_build_allow_list_took: 2.1ms
objects_took: 36.8ms

Filtrar y buscar sale barato aquí. Cerca de tres cuartas partes del tiempo se van en cargar objetos desde el disco. Merece la pena mirar la caché de páginas y el almacenamiento de ese nodo, y un limit menor o un payload más ligero pueden ayudar.

Segundo caso: una consulta cargada de filtros.

total_took: 61.5ms
filters_build_allow_list_took: 41.2ms
filters_ids_matched: 12,840,000
objects_took: 3.9ms

Doce millones de IDs coincidentes. No es un problema de disco ni de hardware. El filtro es sencillamente demasiado amplio. Acótalo o aplica la condición amplia de otra manera, no como prefiltro sobre todo.

Tercer caso: un índice vectorial comprimido.

vector_search_took: 35.1ms
knn_search_layer_0_took: 9.2ms
knn_search_rescore_took: 25.4ms

Recorrer el grafo lleva solo 9 ms. Casi todo el tiempo vectorial se va en el rescoring, que vuelve a traer del disco vectores de precisión completa. El remedio está en los ajustes de almacenamiento y compresión, no en el grafo.

Las tres soluciones no tienen nada en común. Sin un desglose, las tres habrían llegado como la misma queja: la consulta va lenta.

Cerrar la brecha de visibilidad

Ajustar el rendimiento de las bases de datos vectoriales arrastra desde hace tiempo un problema de visibilidad. El motor siempre sabía adónde iba el tiempo; lo difícil era sacar ese conocimiento. El perfilado de consultas cierra la brecha con el cambio más pequeño posible: un flag, una consulta, una respuesta. Según cuentan, el equipo de solution engineering de Weaviate recurre a él antes que a nada cuando un cliente se queja de lentitud, porque convierte una queja vaga en una etapa con nombre y una solución concreta.

Los equipos que usan Weaviate en producción pueden añadir query_profile=True a su kit de depuración. La próxima vez que alguien diga que una consulta va lenta, la respuesta puede ser un número medido en lugar de una suposición. El anuncio completo, titulado Query Profiling: See Where a Slow Query Spends Its Time, y la página de perfilado de consultas de la documentación oficial recogen los detalles.