Beobachtung

Im Jenkins-Build tl-ci-pr #3 (voller Engine-Build mit allen Datenbanken; Modultests, 4 Skripttest-Shards, SpotBugs und 6 DB-Worker laufen gleichzeitig auf einem 8-CPU-Knoten, #29707) scheiterte:

TestAll.testLargeListPerformance with H2_KB
junit.framework.AssertionFailedError: TLObject.setList(50000 elements) should take less than 30 seconds, but took: 33 s 72.210553 ms

Bei der Analyse zeigte sich außerdem, dass das Setzen einer geordneten Liste (ListStorage, z. B. ein mehrwertiges, geordnetes Referenzattribut) sehr langsam wird, wenn viele neue Elemente vor bereits vorhandenen eingefügt werden – das deckte kein Test ab.

Analyse

Zeitmessung im Test

test.com.top_logic.element.meta.kbbased.storage.TestListStorage (com.top_logic.element) setzte in einer Transaktion eine Liste mit 50.000 Elementen und prüfte, dass das weniger als 30 Sekunden dauert. Gemessen wurde mit StopWatch, also Wanduhrzeit. Wanduhrzeit enthält jede Wartezeit auf eine CPU, die durch andere Prozesse belegt ist; bei mehreren parallelen Test-JVMs (PR-Pipeline #29707) überschreitet der Test das Limit, ohne dass sich ListStorage verändert hat.

Messung auf einem unbelasteten Rechner (H2_KB, Anhängen an eine leere Liste in einer Transaktion):

Ohne Last sind CPU-Zeit und Wanduhrzeit gleich: die gesamte Arbeit (einschließlich eingebetteter H2-Datenbank und Commit) läuft im Test-Thread. Der Knoten im PR-Build war unter Last etwa 7-mal langsamer; das Limit hatte nur 6-fachen Abstand zum Normalwert.

Was der Test prüfte

ListStorage hängt neue Elemente an die Link-Liste an; LiveOrderedAssociationsList.updateOrderOnAppend() vergibt dabei jeweils einen Sortierwert OrderedLinkUtil.APPEND_INC (8192) über dem Vorgänger. Erst wenn der Wertebereich erschöpft ist (MAX_ORDER / APPEND_INC, ca. 262.000 Elemente), wird die Liste neu nummeriert. Weder mit 50.000 noch mit 10.000 Elementen erreicht reines Anhängen die Neunummerierung; der Test prüfte nur die Kosten des Anhängens. Der Verweis des Tests auf #23922 war falsch (das Ticket betrifft die Kafka-Synchronisation).

Einfügen vor bestehenden Elementen

ListStorage.trySetAttributeValue() fügte jedes neue Element, das vor einem bestehenden Element steht, einzeln ein (links.add(destPos, link)). updateIndexOnInsert() gibt dem eingefügten Element einen Sortierwert min(INSERT_INC, Lücke / 2) über dem Vorgänger; folgen mehrere neue Elemente aufeinander, halbiert jedes die verbleibende Lücke. Nach etwa 40 Einfügungen ist die Lücke aufgebraucht und OrderedLinkUtil.updateIndices() nummeriert die gesamte Liste neu – danach beträgt der Abstand wieder höchstens APPEND_INC, so dass sich das wiederholt.

Gemessen (CPU-Zeit eines setList, das k neue Elemente vor k bestehende setzt):

Die Laufzeit wächst stärker als quadratisch. Zum Vergleich: 20.000 Elemente anhängen dauert 1,4 s.

Lösung

• ListStorage fügt jede Folge neuer Elemente vor einem bestehenden Element mit einem einzigen links.addAll(index, folge) ein. updateIndexOnInsert() verteilt die Folge gleichmäßig in der Lücke vor dem bestehenden Element oder nummeriert die Liste – falls die Lücke nicht reicht – einmal für die ganze Folge neu. Neue Elemente am Ende werden ebenfalls gemeinsam angehängt. Das Setzen einer Liste ist damit linear in der Zahl der Elemente: 5.000 Elemente vor 5.000 bestehende einfügen dauert 0,26 s statt 12,7 s CPU-Zeit, 9.000 vor 1.000 dauert 0,3 s statt 5,2 s.
• StopWatch (com.top_logic.basic) liest die Zeit aus einer austauschbaren Uhr (StopWatch(LongSupplier)). StopWatch.createThreadCpuWatch() / createStartedThreadCpuWatch() messen die CPU-Zeit des aktuellen Threads (ThreadMXBean.getCurrentThreadCpuTime()); Wartezeit auf eine freie CPU zählt damit nicht mit. Unterstützt die JVM keine Thread-CPU-Zeit, misst die Uhr die Wanduhrzeit; isThreadCpuTime() gibt an, welche Uhr verwendet wird.
• TestListStorage prüft die CPU-Zeit des Test-Threads (Fehlermeldung nennt CPU- und Wanduhrzeit) mit einem Limit von 3 s für vier Szenarien mit 10.000 Elementen statt 50.000:
  • 10.000 Elemente an eine leere Liste anhängen (ca. 0,3 s),
  • 5.000 Elemente vor 5.000 bestehende einfügen (ca. 0,26 s; mit dem früheren Einzel-Einfügen 12,7 s),
  • 9.000 Elemente vor 1.000 bestehende einfügen – die Folge ist größer als die Lücke (APPEND_INC) und erzwingt eine Neunummerierung (ca. 0,3 s; früher 5,2 s),
  • Einfügen an mehreren Stellen einer kleinen Liste mit Prüfung der Reihenfolge. Der Test läuft in ca. 10 s statt 18,5 s.