Warum eine Weaviate-Abfrage langsam ist: Profiling pro Phase

Die Aussage, eine Abfrage sei langsam, sagt Entwicklern fast nichts. Sie beschreibt ein Symptom. Langsam im Vergleich wozu, und in welchem Schritt? Der Metadatenfilter, der Vektorindex, das Lesen der Ergebnisobjekte von der Festplatte oder das Keyword-Scoring? Solange die Zeit keinem dieser Schritte zugeordnet ist, ist jede Änderung ein Schuss ins Blaue: mehr Speicher, ef anpassen, limit senken. Manchmal hilft eines davon, meistens nichts, und die eigentliche Ursache bleibt unbekannt.

Weaviate hat nun eine Funktion veröffentlicht, die genau auf diesen blinden Fleck zielt. Query Profiling zeigt Phase für Phase, wo eine bestimmte langsame Abfrage ihre Zeit verbracht hat.

Warum das Slow-Query-Log nicht reicht

Das Protokollieren langsamer Abfragen gibt es in Weaviate schon länger. Man setzt zwei Umgebungsvariablen, startet den Knoten neu, und jede Abfrage, die eine Zeitschwelle überschreitet, landet mit Timing-Details im Log. Für einen Zweck passt das gut: Regressionen in der gesamten Flotte über Wochen und Monate unauffällig zu erkennen.

Für den häufigeren Fall taugt es wenig, nämlich wenn eine bestimmte Abfrage gerade jetzt langsam ist und die Ursache sofort gebraucht wird. Vier Schwächen fallen auf:

• Ein Neustart ist nötig, und ein Neustart leert den Page Cache des Betriebssystems. Die ersten Abfragen danach lesen kalte Daten von der Festplatte, sodass die Messung eher den Neustart als die Abfrage widerspiegelt.
• Es arbeitet rückwirkend. Ein Eintrag erscheint erst, wenn eine Abfrage bereits langsam war, also lässt sich die Abfrage, die gerade vor Ihnen liegt, nicht gezielt erfassen. Es bleibt nur, zu warten, bis sie wieder langsam ist.
• Protokolliert wird pro Knoten. Eine einzelne Abfrage verteilt sich auf Shards auf mehreren Maschinen, und jede Maschine erfasst nur ihren Anteil, sodass das Gesamtbild von Hand zusammengesetzt werden muss.
• Es ist ein temporärer Schalter, an den man denken und den man wieder zurücksetzen muss. Weil er außerhalb der Deployment-Konfiguration liegt, gerät er leicht aus dem Takt.

Profiling pro Abfrage

Query Profiling kehrt das Modell um. Statt einer globalen Einstellung, die auf Probleme wartet, wird es für eine einzelne Anfrage aktiviert, und die Zeitaufschlüsselung kommt direkt mit der Antwort zurück. Keine Umgebungsvariablen, kein Neustart, keine Schwelle und nichts, was man hinterher aufräumen müsste.

In Python braucht es dafür einen Import der Metadatenklasse.

from weaviate.classes.query import MetadataQuery

Und ein Flag an der Abfrage selbst.

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)

Der koordinierende Knoten sammelt die Profile aller Shards auf allen beteiligten Knoten und liefert sie gemeinsam zurück, sodass eine einzige Anfrage eine Sicht auf den gesamten Cluster ergibt.

Unterstützt werden die offiziellen Clients für Python, JavaScript und TypeScript, Java (v6) und C# sowie reines gRPC. Allgemein verfügbar wurde die Funktion mit Weaviate v1.38. Ist das Flag aus, kostet es eine einzige boolesche Prüfung; ist es an, liest die Engine zusätzlich Timer aus, was Mikrosekunden kostet. Gedacht ist es fürs Debugging, also lassen Sie es aus dem heißen Pfad in Produktion heraus.

Das Profil lesen

Die Ergebnisse sind nach Shard gruppiert, und Phasen, die nicht gelaufen sind, fehlen. Eine reine Vektorsuche erzeugt daher ein anderes Profil als eine BM25-Suche, und hybride Abfragen enthalten Abschnitte für beides. Diese Felder sollten Sie kennen:

• total_took ist die tatsächliche Laufzeit der Suche auf diesem Shard, und alle anderen Werte erklären einen Teil davon.
• objects_took misst das Lesen der finalen Objekte von der Festplatte, ein Schritt namens Hydration. Ein hoher Wert deutet auf eine festplattengebundene Abfrage hin; prüfen Sie den Page Cache, das limit und die Größe der Payload.
• filters_build_allow_list_took zusammen mit filters_ids_matched zeigt, wie lange die where-Klausel brauchte, um zu einer Liste passender IDs zu werden, und wie groß diese Liste ist. Eine riesige Liste bedeutet einen zu breiten Filter; eine kurze Liste, die trotzdem lange gedauert hat, deutet auf langsame Lesezugriffe auf den invertierten Index hin.
• vector_search_took und knn_search_layer_0_took beschreiben die HNSW-Traversierung. Da der Graph im RAM liegt, bedeutet ein hoher Wert hier CPU-Arbeit, nicht Festplatte. Stimmen Sie ef, Vektordimension und Filterstrategie ab, bevor Sie mehr Hardware bestellen.
• knn_search_rescore_took erscheint nur bei aktivierter Kompression. Dabei werden Vektoren in voller Präzision zurückgelesen, um komprimierte Kandidaten neu zu bewerten, und dieser Lesezugriff kann bis zur Festplatte gehen.
• kwd_3_term_time und kwd_4_bmw_time sind die beiden Keyword-Timer, die man sich merken sollte. Der erste erfasst das Lesen der Posting-Listen für jeden Begriff und hängt von der Anzahl der Begriffe und der Festplattengeschwindigkeit ab. Der zweite ist das BlockMax-WAND-Scoring, das bei langen Posting-Listen und geringer Selektivität wächst.

Drei Profile, drei verschiedene Lösungen

Erster Fall: ein Shard mit einer Gesamtzeit knapp unter 50 ms.

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

Filtern und Suchen sind hier günstig. Rund drei Viertel der Zeit entfallen auf das Laden der Objekte von der Festplatte. Page Cache und Storage auf diesem Knoten verdienen einen Blick, und ein kleineres limit oder eine schlankere Payload können helfen.

Zweiter Fall: eine filterlastige Abfrage.

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

Zwölf Millionen passende IDs. Das ist weder ein Festplatten- noch ein Hardwareproblem. Der Filter ist schlicht zu breit. Schränken Sie ihn ein oder wenden Sie die breite Bedingung anders an als als Vorfilter über alles.

Dritter Fall: ein komprimierter Vektorindex.

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

Die Graph-Traversierung dauert nur 9 ms. Fast die gesamte Vektorzeit geht auf das Rescoring, das Vektoren in voller Präzision von der Festplatte zurückholt. Die Lösung liegt in den Storage- und Kompressionseinstellungen, nicht im Graphen.

Die drei Lösungen haben nichts gemeinsam. Ohne Aufschlüsselung wären alle drei als dieselbe Beschwerde angekommen: Die Abfrage ist langsam.

Die Sichtbarkeitslücke schließen

Das Performance-Tuning von Vektordatenbanken hatte lange ein Sichtbarkeitsproblem. Die Engine wusste immer, wohin die Zeit ging; schwierig war, an dieses Wissen heranzukommen. Query Profiling schließt die Lücke mit der kleinstmöglichen Änderung: ein Flag, eine Abfrage, eine Antwort. Das Solution-Engineering-Team von Weaviate greift Berichten zufolge als Erstes darauf zurück, wenn ein Kunde Langsamkeit meldet, weil es eine vage Beschwerde in eine benannte Phase mit konkreter Lösung verwandelt.

Teams, die Weaviate in Produktion betreiben, können query_profile=True in ihren Debugging-Werkzeugkasten aufnehmen. Wenn das nächste Mal jemand sagt, eine Abfrage sei langsam, kann die Antwort eine gemessene Zahl statt einer Vermutung sein. Details stehen in der vollständigen Ankündigung mit dem Titel Query Profiling: See Where a Slow Query Spends Its Time und auf der Seite zum Query Profiling in der offiziellen Dokumentation.