Activity Log Swapping

expecco · exept:workflow · Entwicklerdokumentation

Activity Log Swapping

Fertige Aktivitätsprotokolle wandern in eine Swap-Datei; im Speicher bleibt ein Stellvertreter von 24 Byte und eine Zeile in den Indextabellen. Konzept, Lebenszyklus der Dateien, Einstellungen, umgesetzte Änderungen, die 30 Tests und die gemessene wie geschätzte Speicherwirkung.

Stand 10.09.2026 Packages exept:workflow, exept:expecco

1. Konzept

Ein Testlauf über mehrere Tage erzeugt Millionen von Log-Einträgen, die bisher vollständig im Speicher bleiben. maxNumberOfChildrenInlog ist per Voreinstellung nil, es gibt also keinen Deckel – und wo einer gesetzt ist, werden die ältesten Einträge schlicht verworfen.

Das Feature schreibt abgeschlossene Logs in eine Datei und ersetzt sie im Baum durch einen Stellvertreter. Zwei neue Objekte tragen das:

Der Swapper

Workflow::ActivityLogSwapper

Gehört zu einem Lauf und ist die einzige Stelle, die dessen Swap-Datei kennt: Er hält die Datei, den Schreibprozess und die Indextabellen, vergibt die Record-Indizes und entscheidet, wann die Datei wieder verschwindet.

Die Referenz

Workflow::ActivityLogReference

Tritt im Baum an die Stelle des ausgelagerten Logs – ein Objekt mit einer einzigen Instanzvariablen. Sie beantwortet jede Frage entweder aus den Tabellen ihres Swappers oder holt den Record aus der Datei nach, und niemand über ihr merkt den Unterschied.

Entscheidend ist dabei nicht das Schreiben an sich, sondern die Aufteilung: Nicht alles am Log wandert in die Datei.

Was im Speicher bleibt und was in die Datei geht

Speicher — Indextabellen

Alles, was der Log-Baum, die Zeitleiste und die Zustandsaggregation zum Zeichnen brauchen.

• filePositions, recordSizes
• states (Verdikt)
• startDeltas, durations
• stepIndices → stepTable
• childIndices (IntegerArray)
• parentIndices
• hasTraces
• expandedNames (nur Namen mit Platzhaltern)
• typeTable (Datentypen)

Folge: Den ganzen Baum aufklappen, die Zeitleiste zeichnen und das Verdikt aggregieren kostet kein einziges Byte Dateizugriff.

Datei — Record je Log

Nur, was erst beim Öffnen eines einzelnen Knotens gebraucht wird.

• inputPinEnvelopes
• outputPinEnvelopes
• traces

Ein Record ist ein eigener BinaryObjectStorage, gerahmt von Magic ELOG und einer 32-Bit-Länge. Damit ist jeder Record ohne Vorwissen lesbar: ein seek, ein read.

Schreiben und Verdrängen sind getrennt

Ein fertiges Log wird beim Beenden der Aktivität nur in eine SharedQueue eingereiht. Ein Hintergrundprozess auf userBackgroundPriority serialisiert und schreibt in 32-KB-Blöcken. Das Verdrängen dagegen – der Austausch des Logs gegen seine Referenz in subActivityLogs – ist ein reiner Zeigertausch ohne jeden Dateizugriff:

Workflow::StandardActivityLog >> subActivityLogsAdd:maxNumberOfChildrenInTree:

numTooMany > 0 ifTrue:[
    swapper isNil ifTrue:[
        "/ unverändertes Verhalten: ohne Swapper gehen die ältesten Logs verloren
        subActivityLogs dropAllSuchThat:[:log| ... ].
    ] ifFalse:[
        "/ #swapOut: macht KEIN I/O und antwortet nil für ein Log, das noch
        "/ nicht geschrieben ist - das bleibt dann einfach im Speicher
        ref := swapper swapOut:log.
        ref notNil ifTrue:[ subActivityLogs at:i put:ref ].
    ].
].

Weil swapOut: nie wartet, kann die Auslagerung den Testlauf konstruktionsbedingt nicht ausbremsen. Was noch nicht geschrieben ist, wird beim nächsten Kind erneut betrachtet.

Geteilte Objekte gehören nicht in die Datei

Steps und Datentypen sind gemeinsam genutzt und langlebig. Sie liegen in einer Tabelle im Speicher; der Record trägt nur einen Index. Beim Datentyp ist das nicht Feinschliff, sondern tragend: DataEnvelope>>type ist ein ExpeccoDatatypeHolder, und der hält eine Instanzvariable project. BinaryObjectStorage serialisiert Instanzvariablen, keine Getter – die komplette Testsuite landete damit in jedem einzelnen Record.

Gemessen an einem Envelope mit einem einzigen Wert (200ms) data = 62 Byte, type = 4.686.964 Byte, davon project = 4.686.930 Byte. Ein Lauf mit 687 Records ergab eine Datei von 806 MB.

Nach Auslagerung der Datentypen in die Tabelle: derselbe Lauf, größter Record 228 Byte, 22 Records = 4.732 Byte.

Was gar nicht erst in die Datei geht

Vier Arten von Werten erreichen einen Record nie. Drei davon fängt encodePayload: stufenweise ab, die vierte muss vorher weg – sie würde anstandslos geschrieben, und genau das ist der Schaden.

Modellobjekte – vor dem ersten Schreibversuch

Steps, Pins, Baustein- und Ausführungsbeschreibungen, Activities: alles unterhalb Workflow::WorkflowModel. Diese Objekte sind speicherbar – deshalb bekommen die Stufen unten sie nie zu sehen. BinaryObjectStorage zieht das ganze Projekt hinter ihnen her, und das Speichern einer Ausführungsbeschreibung hat eine Nebenwirkung auf das lebende Modell:

Workflow::ExecutionDescriptionWithCodeExecutedInExpecco >> storeBinaryDefinitionOn:manager:

"redefined to flush unstorable caches"

self flushCachedActivityClassAndMethod.
super storeBinaryDefinitionOn: stream manager: manager

Das ist für das Speichern eines Projekts gedacht, nicht für einen laufenden Test. Der Schreibprozess trifft die Beschreibung aber mitten im Lauf: Die anonyme Activity-Klasse und die kompilierte Methode sind danach weg, die Beschreibung baut sich beim nächsten Zugriff neue – und die gerade laufende Activity ist Instanz der alten. Der Assert am Anfang jeder Ausführung schlägt zu:

Workflow::ExecutionDescriptionWithCodeExecutedInExpecco >> executeInContext:

self assert:(anActivity class == activityClass).

Gefunden mit einer OPC-UA-Suite, die zur Laufzeit Compounds erzeugt und dabei Steps, Pins und Bausteinbeschreibungen durch Pins reicht. Nur mit eingeschalteter Auslagerung – ohne sie speichert während eines Laufs niemand etwas binär. Der Swapper erkennt solche Werte deshalb vor dem ersten Schreibversuch, allein an der Klasse:

Workflow::ActivityLogSwapper >> isLiveModelObject:

class := anObject class.
(class == Workflow::WorkflowModel
  or:[class inheritsFrom:Workflow::WorkflowModel]) ifTrue:[ ^ true ].

"/ one level of plain collections - a suite which passes model objects around
"/ usually passes collections of them. No size limit here: answering false for
"/ a big collection would let exactly the objects through which must not be
"/ stored, and the check only looks at classes, it sends nothing
(class == Array or:[class == OrderedCollection]) ifTrue:[
    ^ anObject anySatisfy:[:each| self isLiveModelObject:each]
].

^ false

Zusätzlich legt storeBinaryDefinitionOn:manager: die geleerten Caches jetzt wieder zurück, sofern inzwischen keine neuen entstanden sind. Ein Speichervorgang darf ein lebendes Modell nicht beschädigen – auch nicht, wenn er von woanders herkommt.

Werte, die BOS nicht schreiben kann – Stufe 2

Sockets, Dateihandles, Bridge-Proxies – und vor allem die details einer Trace: Dort steckt im Fehlerfall eine Exception, und die zieht Kontexte und Blöcke hinter sich her. BOS bricht ab, der Swapper schreibt den Record erneut, diesmal mit einer Beschreibung statt des Werts. Der Envelope wird dabei zu einer UnrestorableData – genau das, was auch der XML-Decoder in derselben Lage einsetzt.

Die Traces – Stufe 3

Scheitert auch der Ersatz, wird der Record ohne Traces geschrieben. Das meldet encodePayload: seinem Aufrufer zurück, damit die Tabelle hasTraces nichts verspricht, was nicht in der Datei steht. Einen Record ganz zu verlieren wäre das schlechteste Ergebnis – dann fällt beim Vater die Kinderliste auseinander.

Geteilte Objekte – immer

Steps und Datentypen, siehe oben: Sie stehen als Index in einer Tabelle im Speicher.

Wie der Ersatztext entsteht, ist selbst eine Regel: Nur für eine feste Liste von Wertklassen nimmt der Swapper den printString, für alles andere den Klassennamen. Der Schreibprozess sendet fremden Objekten keine Nachricht – ein Bridge-Proxy würde auf printOn: mit einem Fernaufruf in eine Bridge antworten, die gerade den Test fährt.

Was statt des Werts im Record steht

Fall	Erkannt an	Im Record
Modellobjekt	der Klasse, unterhalb WorkflowModel	«unrestorable» <Workflow::Step>
Wert, den BOS nicht schreibt	Fehler beim Schreiben (Stufe 2)	printString bei Wertklassen, sonst <Klassenname>
auch der Ersatz scheitert	zweiter Fehler (Stufe 3)	Record ohne Traces, hasTraces bleibt false
Step, Datentyp	immer	ein Index in eine Tabelle im Speicher

Die Referenz

Ein Objekt mit genau einer Instanzvariablen – kein blanker Integer. Der Grund ist Identität: Die Referenz ist der Slot-Inhalt in subActivityLogs, und die Aufrufer arbeiten mit includesIdentical: und identityIndexOf:.

Diese eine Variable trägt zwei Dinge: In den oberen Bits die laufende Nummer des Swappers, in den unteren 24 den Index in dessen Tabellen. Damit findet eine Referenz ihre Daten auch dann noch, wenn längst ein neuer Lauf mit eigenem Swapper läuft.

Workflow::ActivityLogSwapper class >> initialize

"/ 24 bits leave 38 for the number on a 64bit image, 20 leave 10 on a 32bit one
RecordIndexBits := SmallInteger maxVal highBit > 32 ifTrue:[24] ifFalse:[20].
RecordIndexMask := (1 bitShift:RecordIndexBits) - 1.

Die Aufteilung ist so gewählt, dass der Wert ein SmallInteger bleibt: Ein LargeInteger hinge als zweites Heap-Objekt an jeder einzelnen Referenz. Auf einem 64-Bit-Image bleiben 38 Bit für die Laufnummer – rund 275 Milliarden Läufe bei 16 Millionen Records je Lauf.

Kinderlisten stehen explizit im Index

Records werden in Post-Order geschrieben – ein Knoten also nach seinem gesamten Teilbaum. Das macht den Teilbaum zusammenhängend, aber nie die direkten Kinder: Zwei Geschwister sind immer durch die Nachkommen des zweiten getrennt. Ein Intervall lo..hi scheidet damit aus; childIndices hält je Knoten ein IntegerArray mit den tatsächlichen Indizes. Gemessen an einem Lauf mit zwei parallelen Zweigen: die Wurzel hat die Kinder (21 42).

Nur erfolgreiche Logs werden verdrängt

swapOut: lagert ein Log nur aus, wenn sein Verdikt isSuccess ist. Der Grund steht im Record: Er trägt Eingangs- und Ausgangswerte und die Traces – aber nicht den Fehler. Der wohnt in den Extensions des Logs:

Workflow::StandardActivityLog >> executionError

extensions notNil ifTrue:[ ^ extensions executionError ].
^ nil

Ein ausgelagertes fehlgeschlagenes Log käme also ohne seinen Fehler zurück – Verdikt und Meldung wären weg, und genau die will man sehen. Deshalb antwortet die Referenz auf executionError immer nil, und das ist keine Lücke, sondern eine Zusage.

Ein zweiter, schwächerer Grund: Ein Verdikt kann sich noch ändern, solange unten etwas läuft. Für ausgelagerte Kinder merkt sich der Swapper nur den dominierenden Verdikt (swappedOutStates), und was noch kippen kann, muss erreichbar bleiben. In der Praxis greift das kaum, weil Kinder immer vor ihrem Erzeuger fertig sind.

Die Kehrseite: Ein Lauf, der viele Fehler produziert, lagert entsprechend wenig aus – alle fehlgeschlagenen Knoten bleiben im Speicher. Das Verfahren wirkt dort am besten, wofür es gedacht ist: lange, überwiegend erfolgreiche Läufe. Wollte man auch abgeschlossene Fehlschläge auslagern, müsste der executionError als vierter Slot in den Record – mit demselben Problem wie bei den Traces, siehe Kapitel 02.

Zwei Kinderzahlen, nicht eine

Die vorhandene Einstellung maxNumberOfChildrenInlog ist eine Verlustgrenze: Ohne Swapper wird alles darüber verworfen, man setzt sie also so hoch, wie der Speicher es zulässt. Mit Swapper ist dieselbe Zahl eine Cache-Größe: Nichts geht verloren, der Rest wandert in die Datei, also setzt man sie so niedrig, wie die Anzeige es erträgt. Die beiden Wünsche laufen gegeneinander – deshalb gibt es ein eigenes Feld maxNumberOfChildrenInMemoryWhenSwapping mit Vorgabewert 100.

2. Lebenszyklus

Der Swapper hängt an vier Ereignissen: zum ersten Mal wird verdrängt, ein Lauf endet, der Letzte hört auf hinzusehen, expecco wird beendet. Alles Weitere – Datei anlegen, Schreibprozess starten und stoppen, Datei löschen – folgt daraus. Es gibt genau einen Swapper je Lauf, gemeinsam für alle beteiligten Logger, damit ein von einem Logger ausgelagertes Log über jeden anderen wieder lesbar ist – und ein Lauf, der nie über die Cache-Größe kommt, bekommt gar keinen.

Der Lauf beginnt – Einstellungen lesen

Workflow::AbstractActivityLogger >> initializeSettingsForProject: → setupForSwappingIfEnabled

Der Einhängepunkt ist bewusst nicht executionStarted – das ist ein wirkungsloser Zweitaufruf. Hier werden die drei Benutzereinstellungen gelesen, an den Schalter und an die Swapper-Klasse weitergereicht, und bei aktivem Swapping wird maxNumberOfChildren auf die Cache-Größe umgestellt.

Workflow::AbstractActivityLogger >> initializeSettingsForProject:

"/ swapping is a user setting only, there is no project counterpart - so it
"/ is read whichever branch was taken above
preferences := Expecco::ExpeccoPreferences current.
self class swappingEnabled:preferences shouldSwapActivityLogToFile.
Workflow::ActivityLogSwapper swapDirectory:preferences activityLogSwapDirectory.

self class swappingEnabled ifTrue:[
    maxNumberOfChildren := preferences maxNumberOfChildrenInMemoryWhenSwapping.
].
self setupForSwappingIfEnabled.

Ein Swapper entsteht hier noch nicht. setupForSwappingIfEnabled setzt nur die Kinderzahl – ohne Grenze würde nie etwas verdrängt –, und falls keine gesetzt ist, den Vorgabewert 100. Die Methode kann während eines Laufs mehrfach aufgerufen werden und ist deshalb idempotent.

Der erste Überlauf – jetzt wird der Swapper geholt

Workflow::StandardActivityLog >> subActivityLogsAdd:maxNumberOfChildrenInTree: → Workflow::AbstractActivityLogger >> swapperForSwapOut → Workflow::ActivityLogSwapper class >> acquireFor:

Der Swapper wird erst angefordert, wenn ein Knoten zum ersten Mal mehr Kinder hat, als die Cache-Größe erlaubt. Das ist wichtig, weil jeder Testfall eines Testplans seinen eigenen Logger bekommt: Ein Testfall, der unter der Grenze bleibt, kostet dadurch gar nichts – keine Datei, keinen Schreibprozess, keine Indextabellen. In einem Schleifenlauf aus vielen kurzen Testfällen ist das der Normalfall.

Workflow::AbstractActivityLogger >> swapperForSwapOut

(swapper notNil and:[swapper isStopped not]) ifTrue:[ ^ swapper ].
self class swappingEnabled ifFalse:[ ^ nil ].

swapper := Workflow::ActivityLogSwapper acquireFor:self.
^ swapper

Ein noch laufender Swapper wird behalten, niemals freigegeben und neu angelegt: Ein Freigeben würde die Datei löschen, während die Referenzen im Baum noch Indizes hineintragen – kein Fehler, nur falsche Daten. Ein gestoppter wird ersetzt, denn ein neuer Lauf muss wieder schreiben.

acquireFor: nutzt diesen Moment zugleich als Aufräumzeitpunkt (Schritt 07) und schließt einen liegengebliebenen Swapper, dessen Logger sich alle nie abgemeldet haben – sonst schriebe jeder folgende Lauf an dieselbe Datei an. addLogger: trägt den Logger schließlich in activeLoggers und schwach in knownLoggers ein.

Alles, was vor diesem Zeitpunkt fertig wurde, ist nie eingereiht worden – es gab ja keinen Swapper. Das wird sofort nachgeholt, in Post-Order:

Workflow::ActivityLogSwapper >> enqueueFinishedLogsIn:

anActivityLogOrNil isActivityLogReference ifTrue:[ ^ self ].

(children := anActivityLogOrNil subActivityLogs) notNil ifTrue:[
    children do:[:each| self enqueueFinishedLogsIn:each ].
].

"/ the path which is still running must NOT be written: it is not stable
"/ yet, and more children are still to come
anActivityLogOrNil isFinished ifTrue:[
    self enqueue:anActivityLogOrNil
].

Ohne das Nachholen bliebe nicht nur Speicher liegen. Ein Vater wird nur geschrieben, wenn jedes seiner Kinder schon in der Datei steht – findet write: für eines keinen Index, bricht es ab und schreibt den Vater gar nicht:

Workflow::ActivityLogSwapper >> write:expandedName:

(indices includes:nil) ifTrue:[
    "/ one of my children is not in the file - its write failed, or
    "/ the queue was full when it finished. Writing me anyway would
    "/ give me a record whose children are silently missing, and
    "/ swapping me out would then lose them for good.
    "/ Staying in memory is the safe answer: without a record I can
    "/ never be displaced
    ^ self
].

Das ist sicher, aber es kostet: Der Vater bleibt mitsamt seinem ganzen Teilbaum im Speicher, und ohne Record kann er auch später nicht mehr verdrängt werden. Genau diesen Fall vermeidet das Nachholen – es sorgt dafür, dass die früher fertigen Kinder ihren Index haben, bevor der Vater an die Reihe kommt.

Die Datei entsteht (Datei da)

Workflow::ActivityLogSwapper >> start

Jetzt erst wird eine Datei angelegt – atomar über FileStream newTemporaryIn:nameTemplate:, im eingestellten Verzeichnis oder im Temp-Verzeichnis des Images.

Workflow::ActivityLogSwapper >> start

swapStream := FileStream
                newTemporaryIn:self class swapDirectory
                nameTemplate:'expeccoActivityLog%1_%2.swap'.
swapStream binary.

"/ as an AutoDeletedFilename the file goes away when expecco quits, and
"/ also if I am collected without anybody having sent me #discardSwapFile
swapFile := swapStream fileName asAutoDeletedFilename.

"/ they grow as needed - see InitialTableSize in #initialize
filePositions := OrderedCollection new:InitialTableSize.
...
AccessLock critical:[
    Registry add:self.
    swapperNumber := Registry size.
].

Der Name trägt die Prozess-ID des schreibenden Images (%1) – das ist die Grundlage für Schritt 10. Die Registrierung liefert die Swapper-Nummer, die jede Referenz in den oberen Bits ihres Index mitführt; ein einmal vergebener Registry-Platz wird nie wiederverwendet, sonst läse eine Referenz eines freigegebenen Laufs die Records eines fremden. Danach werden die neun Indextabellen angelegt – klein, sie wachsen selbst – und der Schreibprozess auf userBackgroundPriority gestartet.

Während des Laufs

Workflow::StandardActivityLog >> subActivityLogsAdd:maxNumberOfChildrenInTree: · Workflow::ActivityLogSwapper >> enqueue: / swapOut:

Ein fertiges Log wird eingereiht (enqueue:) und vom Hintergrundprozess in 32-KB-Blöcken geschrieben. Sobald ein Knoten mehr Kinder hat, als die Cache-Größe erlaubt, ersetzt swapOut: die ältesten bereits geschriebenen durch Referenzen. Beides ist entkoppelt: Verdrängen macht kein I/O und wartet nie.

Workflow::ActivityLogSwapper >> enqueue:

"/ If the queue is full, this log is simply not written and can therefore
"/ never be swapped out. Best effort by design
stopped ifTrue:[ ^ self ].
anActivityLog isNil ifTrue:[ ^ self ].
writeQueue size >= MaxQueueSize ifTrue:[ ^ self ].
writeQueue nextPut:(Array with:anActivityLog with:(self expandedNameFor:anActivityLog)).

In die Queue geht ein Paar: das Log und sein ausgeschriebener Name. Ein Stepname darf Platzhalter enthalten, die aus den Pin-Werten gefüllt werden – und einen Pin-Wert nach seinem printString zu fragen, ist genau das, was der Schreibprozess nicht tun darf: Der Wert kann ein Bridge-Proxy sein, dessen Bridge gerade den Test fährt. Deshalb expandiert enqueue: den Namen dort, wo der Baustein eben gelaufen ist – im Thread des Testlaufs, wo expecco beim Zeichnen des Baums dieselbe Frage stellt.

Vorberechnet wird nur, was Platzhalter hat: expandedNameFor: antwortet sonst nil, und nur ein Name ungleich nil landet in der Tabelle expandedNames. Alle übrigen Namen leitet nameAt: beim Lesen aus dem Step ab – ohne Dateizugriff und ohne Pin-Werte.

Weil ein Log auf diesem Weg ausbleiben kann – volle Queue, fehlgeschlagene Serialisierung –, prüft write:expandedName:, ob jedes Kind einen Index hat, bevor es den Vater schreibt:

Workflow::ActivityLogSwapper >> write:expandedName:

"/ a child which has already been swapped out is no longer in
"/ writtenLogs (#swapOut: removes it there) - but it knows its own
"/ index, being an ActivityLogReference by now. That index carries
"/ a swapper number, which #recordIndexOfReference: strips off
indices := anActivityLog subActivityLogs
                collect:[:each|
                    each isActivityLogReference
                        ifTrue:[ self recordIndexOfReference:each ]
                        ifFalse:[ writtenLogs at:each ifAbsent:nil ]].

(indices includes:nil) ifTrue:[
    ^ self   "/ siehe oben: dann bleibt der Vater im Speicher
].

Der Lauf endet (Datei bleibt)

Workflow::AbstractActivityLogger >> executionFinished → Workflow::ActivityLogSwapper >> removeLogger:

Der Logger meldet sich ab. Erst wenn der letzte Logger fort ist, wird stop gesendet: Sentinel in die Queue, auf den Schreibprozess warten, Puffer schreiben, Stream schließen. Die Datei bleibt bestehen – Report, Log-Ansicht und Zeitleiste lesen danach weiter aus ihr.

Workflow::ActivityLogSwapper >> removeLogger:

shouldStop := AccessLock critical:[
    aLogger notNil ifTrue:[ activeLoggers remove:aLogger ifAbsent:[] ].
    self dropFinishedLoggers.
    activeLoggers isEmpty
].
shouldStop ifTrue:[
    "/ NOT under AccessLock - #stop waits for the writer process,
    "/ which needs the lock itself in #appendRecord:
    self stop.
].

dropFinishedLoggers wirft dabei Logger heraus, deren Lauf zu Ende ist, die sich aber nie abgemeldet haben (Abbruch, Ausführungspfad ohne executionFinished).

Solange jemand hinsieht

Workflow::ActivityLogSwapper >> isInUse

Eine Swap-Datei darf verschwinden, wenn niemand ihre Records mehr liest. Drei Bedingungen, von denen jede allein genügt:

Workflow::ActivityLogSwapper >> isInUse

activeLoggers notEmptyOrNil ifTrue:[ ^ true ].  "/ ein Lauf schreibt noch
knownLoggers notEmptyOrNil ifTrue:[ ^ true ].   "/ ein Baum ist auf dem Schirm
^ references notEmptyOrNil                      "/ jemand hält Referenzen

activeLoggers hält stark, wer noch schreibt; knownLoggers schwach jeden je bedienten Logger; references ist eine WeakValueDictionary der ausgegebenen Stellvertreter. Die beiden schwachen Sammlungen leeren sich von selbst. Die dritte Bedingung ist unverzichtbar, weil die Zeitleiste in ihren Blöcken nur die einzelnen Logs hält, nicht die Wurzel des Baums – und eine Referenz selbst hält nichts. Eine falsche Antwort hinkt der Wahrheit nach: Unerreichbar ist ein Objekt lange vor dem Einsammeln. Das schadet niemandem – eine Datei ein wenig länger zu behalten kostet nichts.

Aufräumen im Vorbeigehen (Datei weg, wenn ungenutzt)

Workflow::ActivityLogSwapper class >> releaseUnusedSwappers · basicReleaseUnusedSwappers

Ausgelöst an zwei Stellen, die beide ein Loslassen bedeuten: beim Start eines Laufs (aus acquireFor:) und wenn der Testplan-Editor sein zwischengespeichertes Gesamtlog verwirft (TestplanPO >> flushCachedActivityLog).

Freigegeben wird jeder Swapper, der gestoppt ist und entweder nicht mehr in Gebrauch ist oder dessen Datei hinter seinem Rücken verschwunden ist (swapFileIsGone); discardSwapFile stoppt ihn, löscht die Datei und leert seinen Registry-Platz – danach findet eine Referenz dieses Laufs keinen Swapper mehr, statt unter derselben Nummer fremde Records zu lesen. Ein Lauf in Gebrauch wird nie angetastet, die Datei kann also keiner offenen Ansicht unter den Füßen weggezogen werden.

Workflow::ActivityLogSwapper class >> basicReleaseUnusedSwappers

"/ #discardSwapFile sends #stop, which waits for the writer - and that one
"/ needs AccessLock itself. So pick under the lock, release outside it
unused := AccessLock critical:[
    Registry select:[:each|
        each notNil
          and:[each isStopped
          and:[each isInUse not or:[each swapFileIsGone]]]
    ]
].
unused do:[:each| each discardSwapFile ].

Daraus folgt, dass die Gesamtgröße nur eine weiche Grenze sein kann: Wird MaxTotalSwapFileSize (1 GB) überschritten, ist der wahrscheinlichste Grund, dass unerreichbare Logger noch nicht eingesammelt wurden – also einmal garbageCollect und noch einmal hinsehen. Bleibt es dabei, werden die Läufe tatsächlich alle noch betrachtet; dann gibt es eine Warnung ins Log, statt einen davon zu zerstören.

Der Benutzer löscht alle Ergebnisse (Datei weg)

Expecco::Browser >> removeAllTestResults · removeAllTestResultsInSystem · removeAllTestDemoResultsInSystem

Hier gilt etwas anderes als in Schritt 07: Nach Remove all Results sollen die Ergebnisse wirklich weg sein, und eine Datei, die bleibt, weil irgendein Fenster noch eine Referenz hält, wäre genau das, was der Benutzer nicht wollte. releaseAllFinishedSwappers gibt deshalb jeden beendeten Lauf frei, ob betrachtet oder nicht; nur ein noch schreibender bleibt unangetastet. Ansichten, die einen solchen Lauf noch zeigen, bekommen anschließend isBrokenActivityLog = true und überspringen die Einträge, statt in ein nil startTimeAt: zu laufen.

Workflow::ActivityLogSwapper class >> releaseAllFinishedSwappers

finished := AccessLock critical:[
    Registry select:[:each| each notNil and:[each hasActiveLoggers not]]
].
finished do:[:each| each discardSwapFile ].

expecco wird beendet (Datei weg)

Filename >> asAutoDeletedFilename · Workflow::ActivityLogSwapper >> swapFileIsGone

Die Datei ist von Anfang an ein AutoDeletedFilename; deren Lobby wird auf #aboutToQuit geleert. Damit verschwinden die Dateien auch dann, wenn niemand aufgeräumt hat.

Workflow::ActivityLogSwapper >> swapFileIsGone

^ swapFile isNil or:[ swapFile exists not ]

Nebenwirkung, die abgefangen werden muss: Wird nur die Anwendung geschlossen, während das Image weiterläuft, leert die Lobby ebenfalls – die Datei ist fort, der Swapper aber noch da. Records, die nicht mehr gelesen werden können, sind schlimmer als gar keine, deshalb fällt ein solcher Swapper beim nächsten Aufräumen heraus, auch wenn noch jemand Referenzen hält.

Das Image ist abgestürzt (Datei weg)

Workflow::ActivityLogSwapper class >> removeOrphanedSwapFiles

Nach Absturz, kill oder Maschinenneustart bleiben Dateien liegen. Beim nächsten Laufstart werden sie eingesammelt – sicher, weil der Dateiname die Prozess-ID trägt: Die eigenen Dateien nennen immer einen lebenden Prozess, die eines parallel laufenden expecco ebenfalls. Nur eine Datei, deren Prozess fort ist, gehört niemandem mehr. Fehler beim Löschen (fremde Datei, schreibgeschütztes Verzeichnis, abgehängtes Laufwerk) werden protokolliert und ignoriert – Aufräumen darf einen Lauf nie am Starten hindern.

Workflow::ActivityLogSwapper class >> removeOrphanedSwapFiles

(dir filesMatching:prefix , '*.swap') do:[:eachName| |pid|
    pid := Integer readFrom:((eachName copyFrom:prefix size + 1) upTo:$_) onError:nil.
    (pid notNil and:[(OperatingSystem isProcessIdPresent:pid) not]) ifTrue:[
        (dir construct:eachName) remove.
    ].
].

Wer gibt was frei

Auslöser	Methode	Umfang
Lauf startet · Testplan verwirft sein Gesamtlog	releaseUnusedSwappers	gestoppte Läufe, die niemand mehr betrachtet, plus solche ohne Datei; darüber hinaus verwaiste Dateien toter Prozesse
Menü Remove all Results	releaseAllFinishedSwappers	alle beendeten Läufe, unabhängig davon, ob noch jemand hinsieht
expecco beenden · Anwendung schließen	AutoDeletedFilename	alle Dateien des Images
Absturz des vorigen Images	removeOrphanedSwapFiles	Dateien, deren Prozess-ID zu keinem lebenden Prozess gehört

Ein loses Ende

releaseUnusedSwappersCollectingFirst – releaseUnusedSwappers mit vorgezogenem garbageCollect – wurde für den Menüpunkt Remove all Results geschrieben und dort später durch releaseAllFinishedSwappers ersetzt. Die Methode hat derzeit keinen Sender; sie kann vor dem Checkin entfallen oder als Werkzeug stehen bleiben.

3. Einstellungen

Drei Felder unter Einstellungen → Ausführung → Aktivitätsprotokoll. Alle drei sind Benutzereinstellungen und gelten damit für dieses expecco, nicht für eine Testsuite: Sie werden mit den Benutzereinstellungen gespeichert, wandern nicht mit dem Projekt und stehen auch in keiner .ets-Datei.

Ein Projekt-Gegenstück gibt es bewusst nicht. Die übrigen Protokoll-Einstellungen auf derselben Seite kann ein Projekt überschreiben – dafür sorgt der Schalter useUserActivityLogSettings in den Ausführungseinstellungen des Projekts. Für das Auslagern gilt das nicht: Ob es sich lohnt, hängt an der Maschine, auf der gefahren wird – an ihrem Speicher und daran, wohin geschrieben werden darf –, nicht an der Testsuite. Deshalb liest initializeSettingsForProject: diese drei, gleich welchen Zweig der Schalter nimmt.

☐ Swap Finished Activity Logs to a File

shouldSwapActivityLogToFile · Vorgabe: aus

Der Hauptschalter. Ausgeschaltet bleibt alles wie bisher, es wird keine Datei angelegt und kein Prozess gestartet – das lohnt sich erst bei langen Läufen. Die beiden folgenden Felder hängen über enableChannel: an ihm, ihre Beschriftungen über enableDisableColorChannel:.

Max. Nr. of Subactivities Kept in Memory: [ 100 ]

maxNumberOfChildrenInMemoryWhenSwapping · Vorgabe: leer → 100

Die Cache-Größe je Knoten, nicht die Verlustgrenze maxNumberOfChildrenInlog (siehe Kapitel 01). 100 lässt eine normale Ansicht vollständig im Speicher und verdrängt trotzdem eine Schleife mit hunderttausend Durchläufen.

Bleibt das Feld leer, zeigt es den Vorgabewert grau und kursiv an – der Wert kommt aus dem Code, nicht aus der Spezifikation, und bleibt damit auch dann richtig, wenn die Vorgabe geändert wird:

Expecco::LogSettingsApp >> postBuildMaxChildrenInMemoryField:

aField emptyFieldReplacementText:
    Workflow::AbstractActivityLogger defaultMaxNumberOfChildrenWhenSwapping printString

Swap File Directory: [ /tmp ] […]

activityLogSwapDirectory · Vorgabe: leer → Filename tempDirectory

Eingabefeld mit Verzeichnisauswahl über den …-Knopf; leer zeigt grau das tatsächlich verwendete Temp-Verzeichnis. Ein eigenes Verzeichnis lohnt sich auf Maschinen, deren Temp-Verzeichnis eine RAM-Disk ist – das Activity-Log auf eine RAM-Disk auszulagern hebt den Zweck der Sache auf –, und für lange Läufe, die dort echten Platz brauchen.

Gespeichert wird ein String, keine Filename: Die Einstellungsdatei enthält literale Arrays, und ein Filename hat keine literale Kodierung. Ein leerer Wert entfernt den Schlüssel wieder.

Geprüft wird beim Speichern, nicht beim nächsten Lauf

Ein Verzeichnis, in das nicht geschrieben werden kann, fiele sonst erst zu Beginn des nächsten Laufs auf – als Warnung im Log, wenn der Benutzer längst woanders ist. saveSettings bricht deshalb vorher ab:

Expecco::LogSettingsApp >> checkSwapDirectory

path isEmpty ifTrue:[ ^ true ].         "/ leer ist in Ordnung: Temp-Verzeichnis

dir := path asFilename.
dir exists ifFalse:[
    (Dialog confirm:'The swap file directory %1 does not exist.\Create it?') ifFalse:[ ^ false ].
    ... dir recursiveMakeDirectory ...
].
dir isDirectory ifFalse:[ Dialog warn:'%1 is not a directory.'. ^ false ].
dir isWritable ifFalse:[ Dialog warn:'%1 is not writable.'. ^ false ].
^ true

Ablage und Übersetzung

Expecco::ExpeccoPreferences >> activityLogSwapDirectory:

"/ a Filename is stored as a String: the settings file holds literal
"/ arrays, and a Filename has no literal encoding
(path isNil or:[path withoutSeparators isEmpty]) ifTrue:[
    identityAspects removeKey:#activityLogSwapDirectory ifAbsent:[].
    ^ self
].
identityAspects at:#activityLogSwapDirectory put:path withoutSeparators

Alle drei Werte liegen in identityAspects von Expecco::ExpeccoPreferences; ein Eingriff in den encodingVector ist damit nicht nötig. Die Beschriftungen und Hilfetexte stehen als sieben Zeilen in resources/de.rs – die übrigen Sprachen fehlen noch, was der Lint für fr.rs auch meldet.

4. Änderungen im Code

Neue Klassen

exept:workflow, Kategorie Workflow-Execution-Log

Klasse	Aufgabe
ActivityLogSwapper	Hält Datei, Schreibprozess und die Indextabellen eines Laufs. Klassenseitig die Registry, über die eine Referenz ihren Swapper anhand der kodierten Nummer findet, sowie das Aufräumen der Dateien.
ActivityLogReference	Stellvertreter im Baum, eine Instanzvariable. Beantwortet Name, Verdikt, Zeiten, Kinder und Traces aus den Tabellen – dazu das gesamte lesende Trace-Protokoll eines Logs, damit ein Aufrufer eine ausgelagerte Aktivität nicht von einer lebenden unterscheiden kann. Alles Weitere liest den Record oder holt das ganze Log aus der Datei zurück (materialize). Ist ihr Swapper freigegeben, antwortet sie auf jede Anzeigefrage wie ein BrokenActivityLog. doesNotUnderstand: liest im Auslieferungsimage das Log zurück und meldet im Entwicklungsimage.

Geänderte Klassen

Klasse	Package	Änderung
AbstractActivityLogger	workflow	Klassenvariablen SwappingEnabled und DefaultMaxNumberOfChildrenWhenSwapping; neu setupForSwappingIfEnabled und swapperForSwapOut. initializeSettingsForProject: liest die drei Einstellungen und setzt die Kinderzahl; der Swapper selbst entsteht erst beim ersten Verdrängen. executionFinished meldet den Logger ab, behält aber die Swapper-Referenz für die Verdikt-Aggregation.
StandardActivityLog	workflow	subActivityLogsAdd:maxNumberOfChildrenInTree: verdrängt statt zu verwerfen, sobald ein Swapper hängt; computeActivityLogState zieht das aggregierte Verdikt der ausgelagerten Kinder heran; neu setupFromSwappedRecord:step:state:startTime:endTime:logger: baut ein Log aus einem zurückgelesenen Record wieder auf.
Activity	workflow	basicFinishMeWriteValues:writeEno:canCheckForNewActivity: reiht das fertige Log beim Swapper ein.
Object	workflow	Extension isActivityLogReference.
TimelineView	workflow	Verwirft die gemerkte Auswahl beim Neuaufbau der Blöcke und zeichnet keine Blöcke, deren Log nicht mehr lesbar ist.
ExecutionDescriptionWithCodeExecutedInExpecco	workflow	storeBinaryDefinitionOn:manager: legt die geleerten Caches (activityClass, method) nach dem Speichern wieder zurück, sofern inzwischen keine neuen entstanden sind – siehe Kapitel 01.
ExpeccoPreferences	expecco	Drei Einstellungen als identityAspects: shouldSwapActivityLogToFile, maxNumberOfChildrenInMemoryWhenSwapping, activityLogSwapDirectory. Kein Eingriff in den encodingVector nötig.
LogSettingsApp	expecco	Checkbox, Zahlenfeld und Verzeichnisfeld mit Auswahldialog im Dialog Log; Prüfung des Verzeichnisses beim Speichern samt Angebot, es anzulegen; die jeweiligen Vorgabewerte erscheinen grau im leeren Feld.
Browser	expecco	Die drei Wege, die Testergebnisse entfernen, geben anschließend die Swap-Dateien der beendeten Läufe frei.

Ressourcen

Sieben Zeilen in de.rs – zwei Feldbeschriftungen, ein Feldname und vier Dialogmeldungen. en.rs bleibt unberührt, da der Schlüssel selbst der englische Text ist.

Die drei tragenden Methodenpaare

Datentyp aus dem Record heraushalten

Workflow::ActivityLogSwapper >> detachTypesFrom:

detachTypesFrom:envelopesOrNil
    "... An envelope's type is an ExpeccoDatatypeHolder, and that one holds
     the PROJECT: storing it writes the whole test suite into the record"
    ^ envelopesOrNil collect:[:each| |slot holder copy|
        slot := self typeSlotIndexIn:each.
        (slot == 0 or:[(holder := each instVarAt:slot) isNil])
            ifTrue:[ { each. nil } ]
            ifFalse:[
                copy := each shallowCopy.
                copy instVarAt:slot put:nil.
                { copy. self indexOfType:holder } ]]

readRecordAt: hängt die Typen beim Lesen wieder an, bevor irgendein Aufrufer den Payload sieht. Dadurch blieben logAt:, setupFromSwappedRecord: und alle Envelope-Zugriffe unverändert.

Nummer und Index verpacken

Workflow::ActivityLogSwapper >> codedIndexFor:

codedIndexFor:index
    index > RecordIndexMask ifTrue:[
        "/ silently letting it overflow would corrupt the swapper number and
        "/ send every following reference to a different swapper"
        ^ self error:(...)
    ].
    ^ (swapperNumber bitShift:RecordIndexBits) + index

Gebaut wird ein kodierter Index an genau einer Stelle, ausgepackt an genau zweien (swapper, recordIndex der Referenz). Innerhalb des Swappers bleibt jeder Tabellenindex ein reiner Record-Index.

Nutzer je Logger zählen, nicht je Aufruf

Workflow::ActivityLogSwapper >> addLogger:

addLogger:aLogger
    "Counted PER LOGGER, not per call: #initializeSettingsForProject: may
     run more than once for the same run, and a plain counter would then
     never come back to zero"
    AccessLock critical:[
        activeLoggers add:aLogger.
        knownLoggers add:aLogger.
    ].

dropFinishedLoggers entfernt zusätzlich Logger, deren Lauf beendet ist, die sich aber nie abgemeldet haben – sonst hielte ein abgebrochener Lauf seine Datei für immer offen.

5. Tests

Zwei Ebenen, bewusst getrennt: 30 Tests, davon 23 schnelle für die Mechanik des Swappers und 7 langsame über einen echten Testplanlauf. Die schnellen brauchen nichts außer exept:workflow, die langsamen den Testplan-Executor aus exept:expecco – und überspringen sich selbst, wenn er fehlt.

Workflow::ActivityLogSwapperTests — die Mechanik, ohne Executor

Test	Aussage
testCodedIndexEncoding	Nummer und Index kommen aus dem kodierten Wert zurück, der Wert bleibt ein SmallInteger, und ein Record über der Maske wird abgelehnt
testSwapFileLifecycle	Datei entsteht mit start, verschwindet mit discardSwapFile, der Registry-Platz wird geleert
testOrphanedSwapFilesOfDeadProcessesAreRemoved	Datei mit toter Prozess-ID wird geräumt, die eines lebenden Prozesses bleibt
testReferenceIsRebuiltAfterItHasBeenCollected	Regression: nach einem erzwungenen garbageCollect liefert referenceAt: eine neue Referenz statt eines Fehlers
testRoundTripOfPinValuesAndTraces	Pin-Werte und Traces kommen unverändert aus der Datei zurück
testSwapOutOfALogWithoutCreator	Regression: ein Log ohne Creator lässt sich auslagern
testChildIndicesAreCompleteAndInOrder	der Record eines Vaters nennt jedes Kind, in derselben Reihenfolge
testRecordIsSkippedWhenAChildIsMissing	Regression: fehlt einem Kind der Index, wird der Vater gar nicht geschrieben und bleibt im Speicher
testSwapperIsCreatedOnDemandOnly	unter der Grenze entsteht kein Swapper, beim ersten Überlauf schon
testLogsFinishedBeforeTheSwapperAreCaughtUp	enqueueFinishedLogsIn: holt die früher fertigen Kinder nach, der noch laufende Vater wird nicht geschrieben
testTreeIsTheSameWithAndWithoutSwapping	derselbe Baum mit Deckel und ohne: gleiche Knotenzahl, gleiche Pin-Werte
testEnqueuedLogIsWrittenByTheWriterProcess	der echte asynchrone Weg über die Queue
testWriterKeepsTheOrderOfTheQueue	Post-Order bleibt erhalten: Kindindex kleiner als Vaterindex
testNothingIsLostWhenTheQueueIsFull	bei voller Queue wird nicht geschrieben, nicht verdrängt – und nichts geht verloren
testIsInUse	die drei Bedingungen einzeln, inklusive „nur noch eine Referenz lebt"
testReferenceAnswersLikeTheLogItReplaced	die Referenz beantwortet dieselben Fragen wie das Log, das sie ersetzt hat – Name, Verdikt, Zeiten, Kinder, Traces
testTraceProtocolIsTheSameForAReference	Regression: die 20 lesenden Trace-Selektoren antworten aus den Tabellen, statt in doesNotUnderstand: zu laufen
testUnstorableValuesAreDescribedNotPrinted	nur Wertklassen werden gedruckt, alles andere wird durch seinen Klassennamen beschrieben
testWriterProcessDoesNotAskForeignObjects	ein Zähler in printOn: belegt, dass der Schreibprozess fremde Objekte nicht anspricht
testTraceWithUnstorableDetailsIsStillWritten	Stufe 2: eine Trace mit unspeicherbarem details landet trotzdem im Record, das Detail als Text
testLiveModelObjectsAreNotWrittenToTheSwapFile	Regression: ein Modellobjekt am Pin wird ersetzt, bevor etwas geschrieben wird – und der Baustein behält seine Activity-Klasse
testStoringADescriptionKeepsItsCachedActivityClass	Regression: ein binäres Speichern lässt die Caches einer lebenden Ausführungsbeschreibung stehen
testReferenceOfAReleasedSwapperAnswersLikeABrokenLog	Regression: ist der Swapper freigegeben, beantwortet die Referenz jede Anzeigefrage wie ein defektes Log, statt in ein nil zu laufen

Workflow::ActivityLogSwappingRunTests — der Gesamtablauf, headless über den Executor

Test	Aussage
testTreeIsTheSameWithAndWithoutSwapping	derselbe Testplan mit Cache 2 und ohne Swapping: gleiche Knotenzahl, gleiche Namen, gleiche Werte und gleiche Datentypen
testEveryNodeKeepsItsOwnValues	jeder Schritt trägt seinen eigenen Wert; alle paarweise verschieden, Zeitstempel im Laufzeitfenster
testSwapFilesAppearAndGoWithTheResults	nach dem Lauf liegen Dateien da, mit dem Verwerfen der Ergebnisse sind sie weg
testReportContainsEveryNode	der Report liest die ausgelagerten Knoten zurück und nennt jeden Schritt
testElfExportContainsEveryNode	der elf-Export ebenso – das Archiv wird mit getResultOrNilFromFilename: wieder eingelesen und Knoten für Knoten mit dem gelaufenen Baum verglichen; danach ist der Baum noch immer ausgelagert
testLoopingRunKeepsOneResultPerTestcase	Schleifenlauf über drei Zyklen: je Testfall ein Ergebnis, alles lesbar
testNothingIsSwappedWhenTheSwitchIsOff	Gegenprobe: keine Datei, keine Referenz, Baum vollständig

Was die Tests gefunden haben

Drei Fehler, alle aus derselben Ecke – Zustände, die der lesende Teil des Codes längst kannte, an denen der schreibende aber abbrach:

Stelle	Fehler
referenceAt:	at:ifAbsentPut: auf einer WeakValueDictionary: Ist der Wert eingesammelt, bleibt der Schlüssel stehen, der Block läuft nicht, und die Dictionary wirft einen Fehler statt eine neue Referenz zu liefern
swapOut:	schrieb den Creator ungeprüft in eine WeakValueDictionary – und nil ist dort kein gültiger Wert. Ein Log ohne Creator ist überall sonst ein vorgesehener Zustand; der Absturz wäre mitten im Ausführungspfad passiert
flushWriteBuffer	schrieb in den Stream, den stop längst geschlossen hatte – ein zweites stop oder ein discardSwapFile danach brach ab

Was die Tests nicht gefunden haben

Die drei jüngsten Fehler kamen nicht aus der Testsuite, sondern aus einem echten Lauf mit einer fremden Suite. Alle drei haben dieselbe Wurzel: Die Fixtures reichten nur Wertobjekte durch die Pins, bauten den Baum von Hand und gaben ihre Swapper erst beim Aufräumen frei.

Fehler	Warum kein Test ihn traf
Referenz versteht forEachTraceDo: nicht	Kein Test las die Traces über den Baum. Der Report tut es – und im Entwicklungsimage meldet doesNotUnderstand:, statt das Log still aus der Datei zu holen
Referenz eines freigegebenen Swappers läuft in ein nil	Kein Test hielt einen Baum, dessen Swapper schon weg war. Die Baumansicht tut genau das: Sie zeichnet weiter, nachdem die Ergebnisse verworfen wurden
Modellobjekt am Pin zerstört die Activity-Klasse	Kein Test reichte ein Modellobjekt durch einen Pin. Dass ausgerechnet ein speicherbarer Wert Schaden anrichtet, stand in keiner Annahme – gesucht wurde nach Werten, die BOS nicht schreiben kann

Für alle drei gibt es jetzt Tests, und sie prüfen die Ursache statt des Symptoms: dass das Trace-Protokoll ohne doesNotUnderstand: auskommt, dass eine Referenz ohne Swapper jede Anzeigefrage beantwortet, und dass ein Modellobjekt ersetzt wird, bevor der erste Schreibversuch läuft – sonst wäre der Test auch dann grün, wenn nur das Zurücklegen der Caches wirkt.

Fünf Fallstricke beim Testen dieses Features

Ohne Executor reiht niemand ein Log ein. Im echten Lauf tut das die Aktivität, wenn sie fertig ist. Ein Test, der Verdrängung erwartet, muss selbst einreihen und warten – sonst hängt das Ergebnis daran, ob der Schreibprozess zufällig drankam. Gewartet wird mit Frist, nie mit festem Delay:

Workflow::ActivityLogSwapperTests >> waitFor:

"/ Tolerant on purpose: the writer runs at background priority, so how long
"/ it takes is not predictable. A fixed delay would be either flaky or slow
deadline := Timestamp now addSeconds:10.
[ aBlock value ] whileFalse:[
    Timestamp now > deadline ifTrue:[ ^ false ].
    Delay waitForMilliseconds:20.
].
^ true

Unverbundene Steps laufen gleichzeitig. Dann werden alle Kinder an den Log gehängt, bevor eines fertig und geschrieben ist – und es wird nie etwas verdrängt. Die Steps des Testprojekts sind deshalb über ihre Enable-Pins verkettet:

Workflow::ActivityLogSwappingRunTests >> buildProjectWithCases:stepsEach:

eno := previous hasEnableOutputPin
            ifTrue:[ previous enableOutputPin ]
            ifFalse:[ previous createEnableOutputPin ].
eni := step hasEnableInputPin
            ifTrue:[ step enableInputPin ]
            ifFalse:[ step createEnableInputPin ].
eno connectWithPin:eni.

Konstante Werte machen blind. Jeder Schritt friert einen eigenen Wert ein (Fall·100 + Schritt) und schreibt ihn über drei Ausgänge verschiedenen Datentyps zurück. Erst dadurch fällt auf, wenn eine Referenz den Record eines anderen Knotens liest – und die drei Typen prüfen zugleich detachTypesFrom:/attachTypesTo::

Testaktion leaf

counter value:(n value).
stamp   value:(Timestamp now).
text    value:('run-', n value printString).
"/ give the activityLog writer process a chance
Delay waitForMilliseconds:20.

Die Enable-Pins schreiben einen eigenen *DONE*-Token mit – beim Auswerten über data isENOToken not herausfiltern, das ist Ablaufsteuerung und keine Nutzdaten. Und loopCount: allein schleift nicht: loop:true ist der Schalter.

Prüfen, bevor gelesen wird. Report und elf-Export lesen die ausgelagerten Knoten aus der Datei zurück. Wer vorher schon die Werte einsammelt, nimmt ihnen genau das weg, was sie prüfen sollen – die Zählung der Referenzen fragt deshalb nur isActivityLogReference und liest keinen einzigen Record.

Was die Prüfung nicht hergibt: Der Standardreport listet Schritte, nicht deren Pin-Werte – geprüft wird also, dass jeder Schritt vorkommt. Und die .elf-Datei ist ein ZIP, dessen Einträge dieses Image nicht wieder auspacken kann; statt einer Textsuche vergleicht der Test die Archivgrößen mit und ohne Auslagerung.

Aufräumen gehört dazu

Beide Klassen setzen im setUp ein eigenes Swap-Verzeichnis und stellen im tearDown jede angefasste Benutzereinstellung zurück – bei den Laufzeit-Tests sind das vier: Schalter, Cache-Größe, Verzeichnis und die Verlustgrenze maxNumberOfChildrenInlog, die für den Vergleichslauf ohne Swapper leer sein muss, damit er nichts verwirft. Jeder erzeugte Swapper wird verworfen, und gelöscht wird rekursiv: Der Report legt neben seinem HTML ein .files-Verzeichnis an.

Laufzeit: die 15 Mechanik-Tests laufen in Sekundenbruchteilen, die 7 Laufzeit-Tests brauchen zusammen rund fünfeinhalb Sekunden.

6. Speicherabschätzung

Gemessen sind die Dateigrößen; die Zahlen für den Hauptspeicher sind Rechnungen aus den Objektlayouts. Grundlage: 64-Bit-Image, Objektkopf 16 Byte, ein Slot 8 Byte – belegt durch StandardActivityLog mit instSize 16 und daraus 144 Byte.

Ein Log-Eintrag ohne Auslagerung

Blattknoten mit einem Eingangs- und zwei Ausgangswerten

Bestandteil	Byte	Rechnung
StandardActivityLog	144	16 + 16 × 8
3 × DataEnvelope	96	je 16 + 2 × 8
2 Envelope-Sammlungen	80	je Array-Kopf + Slots
Verwaltung, Ausrichtung	~120	Erfahrungswert
Summe	~440

Derselbe Eintrag ausgelagert

Bestandteil	Byte	Rechnung
ActivityLogReference	24	16 + 1 × 8
Eintrag in references	~16	WeakValueDictionary, 2 Slots
9 Tabellenzeilen	72	9 × 8 (OrderedCollection-Slot)
2 Timestamp-Objekte	~48	startDeltas, durations
Summe	~160

• je Eintrag vorher: 440 B
• je Eintrag nachher: 160 B
• Einsparung: 64 %
• Faktor: 2,8 ×

Hochgerechnet auf eine Million Einträge

• ohne Auslagerung: 440 MB
• mit Auslagerung, heutiger Stand: 160 MB
• mit den Maßnahmen aus Kapitel 07: ≈ 38 MB

Dazu kommt die Swap-Datei mit rund 200 MB – auf der Platte, nicht im Adressraum. Ihre Größe hängt fast vollständig von den Pin-Werten ab, denn genau die sind der variable Anteil, der ausgelagert wird.

Gemessen am Testlauf

SwapTest20, 22 Records, Cache-Größe 5

Größe	Wert	Anmerkung
Datei gesamt	4.732 B	22 Records inklusive Rahmen
Record, größter	228 B	Blattknoten mit Pin-Werten
Record, kleinster	15 B	Compound ohne eigene Werte
Rahmen je Record	8 B	4 Magic + 4 Länge
Wurzel-Kinder im Speicher	5 von 20	15 durch Referenzen ersetzt

Wovon die Einsparung wirklich abhängt Der feste Anteil eines Logs – Objektkopf, Zeiten, Verdikt, Verweise – schrumpft von rund 240 auf 160 Byte, also nur um ein Drittel. Der große Hebel ist der variable Anteil: Pin-Werte und Traces verlassen den Speicher vollständig. Ein Lauf mit vielen oder großen Pin-Werten profitiert deutlich stärker als die 2,8 × dieser Rechnung, ein Lauf mit leeren Pins entsprechend weniger.

7. Weitere Einsparung

Die verbleibenden 160 Byte je Eintrag stecken fast vollständig in den Indextabellen und im Stellvertreterobjekt. Fünf Maßnahmen, nach abnehmendem Verhältnis von Gewinn zu Risiko.

Zeitstempel als Integer-Deltas

−40 B je Eintrag

Die Instanzvariablen heißen startDeltas und durations, halten aber vollständige Timestamp-Objekte. Bei einer Million Einträgen sind das zwei Millionen Objekte für eine Information, die als Abstand zum Laufbeginn in ein IntegerArray passt: 2 × 4 Byte statt 2 × (8 + 16).

Dafür

• Größter Einzelposten, und die Namen versprechen es ohnehin schon.
• Rein intern; nach außen liefern startTimeAt: und endTimeAt: weiterhin Timestamps.

Dagegen

• Auflösung und Bereich müssen festgelegt werden. logTimesWithMicrosecondPrecision und ein dreitägiger Lauf ergeben 2,6·10¹¹ µs – das braucht 64 Bit, Millisekunden kämen mit 32 aus.
• Jeder Lesezugriff rechnet um.

Referenzobjekte durch blanke Integer ersetzen

−40 B je Eintrag

Die von Anfang an vorgesehene zweite Stufe: subActivityLogs enthält für ausgelagerte Kinder direkt den kodierten Index statt eines Objekts. Das spart die 24 Byte des Stellvertreters und den Eintrag im references-Verzeichnis.

Dafür

• Der zweitgrößte Posten, und er entfällt vollständig statt zu schrumpfen.
• Der kodierte Index existiert bereits und ist genau dafür gebaut.

Dagegen

• Die Identität bricht: includesIdentical: in ActivityLogItem>>basicUpdateChildren und identityIndexOf: in replaceSublog:by: müssen umgebaut werden – und jede weitere Stelle, die einen Sublog wiedererkennt.
• Alle rund 80 Selektoren der Referenz müssten woanders leben; jeder Aufrufer, der heute ein Log-artiges Objekt bekommt, sähe plötzlich einen Integer.
• Der größte Eingriff von allen. Lohnt erst jenseits von etwa einer Million Einträgen.

Typisierte Arrays statt OrderedCollection

−40 B je Eintrag

Neun OrderedCollection kosten je Eintrag neun Zeiger-Slots à 8 Byte. states passt in ein ByteArray, hasTraces in ein Bit, recordSizes, stepIndices und parentIndices in ein IntegerArray; nur filePositions braucht wirklich 64 Bit.

Dafür

• Rein lokal im Swapper, keine Auswirkung nach außen.
• Nebeneffekt: bessere Lokalität beim Durchlaufen großer Bäume.

Dagegen

• Wachstum kopiert den ganzen Puffer; braucht eine Verdopplungsstrategie.
• childIndices speichert nil für Blätter und bleibt eine Objektsammlung – siehe die nächste Maßnahme.

Kinderlisten in einem gemeinsamen Array

−16 B je Knoten mit Kindern

Statt eines eigenen IntegerArray je Knoten ein einziges großes Array plus eine Offsettabelle, wie bei dünn besetzten Matrizen. Das spart je Knoten mit Kindern einen Objektkopf; bei einer Million Knoten mit durchschnittlich einem Kind sind das 16 MB.

Dafür

• Blätter kosten dann gar nichts mehr statt eines nil-Slots.
• Passt zur vorigen Maßnahme, beide betreffen dieselbe Tabelle.

Dagegen

• Kinderlisten entstehen erst beim Schreiben des Elternknotens, also spät – das Anhängen ist unproblematisch, ein nachträgliches Ändern aber teuer.
• childReferencesAt: und noteParentIndicesBelow: werden weniger offensichtlich.

Kleinere Cache-Größe

wirkt sofort, ohne Codeänderung

Die Vorgabe von 100 Kindern je Knoten ist großzügig. Ein Wert von 20 verdrängt früher und hält entsprechend weniger vollständige Logs im Speicher – bei einem Baum mit vielen Verzweigungen ist das der schnellste Hebel überhaupt, weil er den variablen Anteil trifft.

Dafür

• Eine Einstellung, kein Eingriff. Pro Installation wählbar.
• Wirkt auf den teuersten Anteil, die Pin-Werte.

Dagegen

• Jedes Aufklappen eines älteren Knotens liest die Datei.
• Bei einem laufenden Test kann das Verdrängen den Writer einholen; dann bleiben Logs im Speicher, bis sie geschrieben sind.

Summe

je Log-Eintrag, kumuliert

Stand	Byte	bei 1 Mio	gegenüber heute
ohne Auslagerung	440	440 MB	—
heutiger Stand	160	160 MB	2,8 ×
+ Zeitstempel als Deltas	120	120 MB	3,7 ×
+ typisierte Arrays	80	80 MB	5,5 ×
+ Integer statt Referenzobjekt	40	40 MB	11 ×
+ gemeinsames Kinderarray	~38	~38 MB	11,6 ×

Die ersten drei Maßnahmen sind lokal im Swapper und zusammen an einem Tag zu machen. Die vierte ist der eigentliche Einschnitt und sollte erst angegangen werden, wenn ein realer Lauf zeigt, dass die 160 Byte tatsächlich das Problem sind – bis dahin ist die Cache-Größe der bessere Hebel, weil sie den variablen Anteil trifft und nichts kostet.

expecco · Activity Log Swapping · Stand 10.09.2026

Dateigrößen gemessen, Speichergrößen gerechnet aus Objektlayout und instSize.

---

Copyright © 2014-2024 eXept Software AG