Ein neuer Test schlägt fehl. Das kommt unerwartet. Eine NullPointerException? Hier? Ich setze im Code einen Break Point und starte den Test im Debug-Mode. Warum soll diese Variable null sein? Der Test stoppt am Break Point. Die Variable ist nicht null. Ich lasse den Test weiterlaufen. Grün.
Ich wiederhole den Test mehrfach im Debug-Mode. Die Variable ist nie null. Ich verlasse den Debug-Mode und starte den Test normal. Der Test ist rot. Ich beiße in den Tisch.
Was ist ein Heisenbug?
Wer diese Erfahrung selbst schon einmal gesammelt hat, ist einem sogenannten Heisenbug begegnet. Das ist ein fehlerhaftes Stück Code, das anscheinend sein Verhalten verändert, wenn man es beobachtet. Die Bezeichnung Heisenbug ist ein Wortspiel, das sich auf den von Werner Heisenberg beschriebenen Beobachtereffekt der Quantenmechanik bezieht.
In der Realität verändert aber nicht der Code sein Verhalten. Wir verändern die Rahmenbedingungen, unter denen der Code läuft, damit wir ihn beobachten können.
Heisenbug-Beispiel 1
Ein kleines Beispiel in Java: Es wird eine Liste mit 100 Elementen erzeugt und mit den Werten “0“ bis “99“ initialisiert. Per stream() wird über die Liste iteriert und das Element “42“ – wenn es gefunden wird – entfernt.
1 class HeisenbugTest {
2
3 List<String> list = new ArrayList<>();
4
5 @Test
6 void heisenbug() {
7 for (int element = 0; element < 100; element++) {
8 list.add(String.valueOf(element));
9 }
10
11 list.stream()
12 .filter(string -> string.equalsIgnoreCase("42"))
13 .forEach(this::removeMember);
14 }
15
16 void removeMember(String element) {
17 list.remove(element);
18 }
19 }
Jetzt wissen wir vielleicht, dass die direkte Manipulation einer Collection während einer stream()-Operation eine schlechte Idee ist (Zeile 13). Da wird es eine ConcurrentModificationException geben.
Ich bekomme aber eine NullPointException!
java.lang.NullPointerException
at
de.pentacor.javabasics.api.HeisenbugTest.lambda$heisenbug$0(HeisenbugTest.java:19)
at
java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:176)
at
java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1654)
at
java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:484)
Wie jetzt? Ich debugge …
Ich komme bis zum 100. Element (hat den Wert “99“ weil wir mit “0” begonnen haben).
Und dann …
Äh Moment! 101 Elemente? Nein, die Liste hat immer noch 100 Elemente. Wo kommt das letzte Element her?
Es folgt der In-den-Tisch-beißen-Moment.
Für mich lichtet sich der Nebel erst mit einem Blick auf die Java Streams Dokumentation:
Unless the stream source is concurrent, modifying a stream's data source during execution of a
stream pipeline can cause exceptions, incorrect answers, or nonconformant behavior.
Aha. Wenn ich statt stream() die Funktion parallelStream() aufrufe oder eine LinkedList statt der ArrayList verwende, ist meine Nerd-Welt wieder in Ordnung. Das Debuggen hat mir jedenfalls nicht geholfen. Im Gegenteil.
Heisenbug-Beispiel 2
Ebenfalls Java: Die Klasse Heisenbug unten besitzt eine Funktion, die die Uhrzeit eines übergebenen Datums in einen String umwandelt.
1 public class Heisenbug {
2
3 private static final SimpleDateFormat SIMPLE_DATE_FORMAT = new SimpleDateFormat("hh:mm:ss,SSS", Locale.getDefault());
4
5 String formatTime(Date date) {
6 return SIMPLE_DATE_FORMAT.format(date);
7 }
8 }
Die Methode formatTime enthält einen Unit-Test der
- ein Datum erzeugt
- die enthaltene Uhrzeit in einen erwarteten Wert konvertiert
- unsere
formatTime-Funktion aufruft - das Ergebnis von
formatTimemit dem erwarteten Wert vergleicht
1 class SynchronizationExampleTest {
2
3 SynchronizationExample cut = new SynchronizationExample();
4
5 @Test
6 void formatDate() {
7 Date date = ...
8 String expected = new SimpleDateFormat("hh:mm:ss,SSS", Locale.getDefault()).format(date);
9 String actual = cut.formatDate(date);
10 assertEquals(expected, actual);
11 }
12 }
Grün. Der Test funktioniert.
In der Realität – auf einem produktiven System – wird die Funktion formatTime oft aufgerufen … von verschiedenen Konsumenten. Und diese Konsumenten beschweren sich, dass die Funktion manchmal Unfug zurückliefert.
Mit viel Mühe haben wir es geschafft, den Fehler lokal nachzuvollziehen. Dazu dient der folgende Code:
1 public class HeisenbugThread extends Thread {
2 public void run() {
3 int count = 0;
4 for (int i = 0; i < 1000; i++) {
5 Heisenbug heisenbug = new Heisenbug();
6
7 Date date = ...
8
9 String actual = heisenbug.formatDate(date);
10 String expected = new SimpleDateFormat("hh:mm:ss,SSS", Locale.getDefault()).format(date);
11
12 if (!formattedDate.equals(expected)) {
13 count++;
14 }
15 }
16 System.out.println("Thread: " + this.getId() + ", wrong results: " + count);
17 }
Der Konsument HeisenbugThread unten erzeugt 1000-mal ein zufälliges Datum. Aus dessen Uhrzeit wird ähnlich wie bei Heisenbug’s formatTime ein String (expected) generiert. Das Ergebnis wird mit dem String, der von formatTime zurückgeliefert wurde, verglichen (Zeile 9). Stimmen der erwartete Zeit-String und der Rückgabewert von formatTime nicht überein, wird ein Zähler erhöht (13). Am Ende wird der Zähler (falsche Ergebnisse) ausgegeben. this.getId() liefert die Id des Threads (16).
Die Klasse Heisenbug bekommt zusätzlich eine main()-Methode.
1 public static void main(String[] args) {
2 new HeisenbugThread().start();
3 new HeisenbugThread().start();
4 }
Starte ich diese main-Methode, erhalte ich beispielsweise folgenden Output:
Thread: 22, falsche Ergebnisse: 101
Thread: 21, falsche Ergebnisse: 88
Von jeweils 1000 Aufrufen von formatDate wurde hier 101- bzw. 88-mal ein falsches Ergebnis zurückgeliefert. Das sollte ich mal debuggen! Also setze ich in Zeile 7 der Klasse HeisenbugThread einen Breakpoint. Ich starte Heisenbug main im Debug Mode und steppe über die Zeilen 9 und 10.
Schade! Keine Diskrepanz.
Laut dem Zähler falsche Ergebnisse oben müsste ca. jeder 10. Durchlauf fehlschlagen.
Leider nichts. Auch nach 100 Durchläufen nicht. Der Code tut mir leider nicht den Gefallen. Solange ich auf den Code schaue, tritt der Fehler nicht auf.
Ich starte die main-Methode der Klasse Heisenbug noch einmal:
Thread: 22, falsche Ergebnisse: 106
Thread: 21, falsche Ergebnisse: 96
Menno!
Was mache ich anders, wenn ich den Code debugge?
Was macht meine Entwicklungsumgebung beim Debuggen? Sie stoppt die Ausführung des Programms am Breakpoint. Für beide HeisenbugThread-Instanzen. Der Heisenbug tritt eventuell nur auf, wenn beide Threads laufen. Das lässt sich prüfen.
1 public static void main(String[] args) {
2 //new MyThread().start();
3 new MyThread().start();
4 }
Und siehe da:
Thread: 21, falsche Ergebnisse: 0
Der Fehler – mein Fehler – muss also eine Stelle betreffen, die von beiden HeisenbugThread benutzt wird.
Nun, natürlich ist der Heisenbug hier konstruiert. Die Klasse Heisenbug verwendet für die Formatierung der Zeit eine Konstante vom Typ SimpleDateFormat. Ein Blick in die javadoc verrät uns:
“Date formats are not synchronized. It is recommended to create separate format instances for each thread. If multiple threads access a format concurrently, it must be synchronized externally.”
Synchronisiert habe ich nicht. Musste ja schiefgehen.
Welche Situationen begünstigen einen Heisenbug?
In der Regel hat ein Heisenbug seine Ursache in Unterschieden in Timing oder parallelen Zugriffen zwischen Realität und Test- bzw. Debug-Situation. Timing und Concurrency spielen bei vielen Konzepten in der (verteilten) Programmierung eine Rolle, beispielsweise bei:
Mehr Tipps zu Ursachen gibt es auf Stack Overflow. Ein Service, der unter einer oder mehreren dieser Situationen läuft, ist Kandidat für Heisenbugs. Das heißt nicht zwangsläufig, dass einer auftreten muss.
Wie kann ich Heisenbugs vermeiden?
Aus meiner Sicht bieten sich hier diverse Ansätze an. Ich vermeide Heisenbugs durch …
- automatisierte Tests jenseits einfacher Unit- oder Integrationstests, die nicht auf parallele Verarbeitung oder Timing Issues ausgelegt sind: Chaos Engineering bietet hier ein gutes, methodisches Toolset. Wenn mein Service für die Nutzung durch viele User vorgesehen ist, teste ich den Zugriff dieser vielen Benutzer. Ein Unit Test gibt lediglich einen Hinweis auf die funktionale Korrektheit meines Codes.
- gutes Verständnis der benutzten Frameworks und Tools: Wenn ich wie im Beispiel oben eine nicht synchronisierte Instanz einer Klasse verwende, sollte ich mir dessen bewusst sein. Spezifikationen lesen hilft genauso wie Erfahrung im Umgang mit den verwendeten Tools.
- gutes Verständnis der verwendeten Konzepte und Architekturen: Lazy Loading und Lazy Initialization sind spannende Konzepte um Ressourcen-Verbrauch und Performance zu balancieren. Wenn ich verstehe, wie diese genau funktionieren und wo ihre Grenzen sind, lerne ich sie zu nutzen, statt an ihnen zu scheitern.
Sind funktionale oder Datenfehler auch Heisenbugs?
Sehr wahrscheinlich nicht. Liefert mein Code unter bestimmten Bedingungen – z.B. bei speziellen Datenkonstellationen – unerwartete Ergebnisse, treten diese Ergebnisse mit den gegebenen Daten wahrscheinlich immer auf. Vorsicht bei Daten, die voneinander abhängen bzw. sich gegenseitig beeinflussen.
Aber es gibt Heisenbugs, die erst bei bestimmten Datenkonstellationen auftreten. Ihre Ursache liegt nicht in den Daten selbst. Sie sind lediglich der Auslöser für den Heisenbug.
Zusammenfassung
In unserer komplexen Service-Welt können sich schwer zu entdeckende Software-Fehler einschleichen. Diese treten erst beim Eintreten bestimmter Bedingungen im Zusammenhang mit Timing oder paralleler Benutzung auf. Scheinbar verändert der Code beim Versuch den Fehler – den Heisenbug – zu entdecken sein Verhalten. Einfache Unit bzw. Integrationstests helfen nicht, Heisenbugs zu entdecken. Beim Debuggen des betroffenen Codes ist die Fehlerursache häufig nicht erkennbar, weil der Debug-Modus nicht der realen Anwendung des Codes entspricht. Genaue Kenntnis der verwendeten Frameworks und Konzepte, aber auch produktionsnahe – z.B. mittels Chaos Engineering – hergestellte Test-Szenarien, helfen Heisenbugs zu vermeiden bzw. zu erkennen.
