Stranger Than Usual

To flush() or not to flush()

Ich habe heute mal ein bisschen herumgespielt, für dass ich eine große HTML-Datei brauchte, die möglichst einheitlich aussehen sollte. Also wirklich groß. Im Gigabytebereich. Diese Datei sollte dann auch nicht in eine Datei geschrieben, sondern direkt an ei verarbeitende Programm weitergegeben werden. Wozu? Dazu vielleicht später mal mehr.

Also habe ich mir ein sehr einfaches Python-Script geschrieben, das zuerst den Beginn des HTML-Dokuments nach stdout schreibt, zuletzt das Ende und dazwischen in einer Schleife einfach immer wieder dieselbe Zeile:

for i in range(approx_size // len(repeated_element)):
    print(repeated_element)

approx_size ist hier die ungefähre Zielgröße der Datei (eigentlich 42 GiB).

Mir ist dann aufgefallen, das je nachdem an welches Programm die Daten weitergereicht werden, das Zielprogramm die Daten schneller verarbeitet als Python sie schreiben kann. Also habe ich das gemacht, was jeder Rust-Enthusiast machen würde: Das ganze noch einmal in Rust geschrieben. Die Ausgabedaten zwischen den beiden Versionen sollten identisch sein. Das Rust-Programm ist auch sehr kurz (ein paar Konstanten mit dem HTML-Inhalt und der Anzahl der Wiederholungen habe ich vorher definiert).

fn main() -> Result<()> {
    let mut out = stdout().lock();

    writeln!(out, "{}", PREFIX)?;

    for _ in 0..REPEATS {
        writeln!(out, "{}", REPEATED)?;
    }

    writeln!(out, "{}", SUFFIX)
}

Also habe ich es ausgeführt und… es lief deutlich langsamer als die Python-Version. Ich habe das mal mit ≈ 42 MiB großen Dateien getestet, weil das deutlich schneller ging:

$ hyperfine "./genbig.py > /dev/null"
Benchmark 1: ./genbig.py > /dev/null
  Time (mean ± σ):     337.7 ms ±  15.5 ms    [User: 333.5 ms, System: 4.3 ms]
  Range (min … max):   324.1 ms … 373.2 ms    10 runs
$ hyperfine "target/release/genbig > /dev/null"
Benchmark 1: target/release/genbig > /dev/null
  Time (mean ± σ):     780.3 ms ±   9.1 ms    [User: 457.9 ms, System: 321.9 ms]
  Range (min … max):   773.5 ms … 805.2 ms    10 runs

Wtf? Das ist weniger als halb so schnell! Woran liegt das? Es ist der release-build, also liegt es sicher nicht an mangelnder Compileroptimierung. Ich habe auch den stdout-lock nur einmal ganz am Anfang geholt, damit das Programm keine Hindernisse zum Schreiben hat.

Ich bin ziemlich schnell auf den Gedanken gekommen, dass es am flushen liegen könnte. print() in python verhält sich nämlich unterschiedlich, je nachdem ob man auf eine Konsole schreibt oder irgendwoanders hin. Bei einer Konsole wird nach jedem print() ein flush gemacht (oder zumindest nach jedem Zeilenumbruch, ich habe das nicht genau nachgeschlagen). Mir ist das wieder eingefallen, weil in umgekehrt mal Probleme damit hatte, dass Python nicht geflushed hat, wenn ich es wollte.

In rust wiederum ist es bei stdout fix. In der Referenz zu stdout steht:

By default, the handle is line-buffered when connected to a terminal, meaning it flushes automatically when a newline (\n) is encountered. For immediate output, you can manually call the flush method.

Aha. Während Python also alles schön in einen Buffer schreibt und dann flushed, wird bei Rust in jeder einzelnen Zeile geflushed. Zum Vergleich: Wenn stdout die Konsole ist, dann sieht es schon ganz anders aus. Dann sind es bei Rust etwa 3 Sekunden und bei Python etwa 4,5 Sekunden (die Konsole ist sehr lahm).

Das Problem ist einfach gelöst: es gibt std::io::BufWriter. Damit wird irgendein Writer gebuffert und nur noch geflushed, wenn der Buffer voll ist oder man manuell flush() aufruft. Ich musste stdout also nur wrappen:

let mut out = BufWriter::new(stdout().lock());

und am Ende noch einmal flush() aufrufen (das passiert auch automatisch, aber dann werden möglicherweise auftretende Fehler ignoriert), und schon geht es deutlich schneller:

$ hyperfine "target/release/genbig > /dev/null"
Benchmark 1: target/release/genbig > /dev/null
  Time (mean ± σ):      26.5 ms ±   1.2 ms    [User: 25.8 ms, System: 1.1 ms]
  Range (min … max):    25.3 ms …  30.7 ms    93 runs

Cool. Also von weniger als halb so schnell zu mehr als zehn Mal so schnell. Es gibt noch ein paar andere Stellen, an denen ich Optimierungsmöglichkeiten sehe, aber das ist mir erst einmal schnell genug, schneller kann es die andere Seite eh nicht verarbeiten.

Fazit

Was lernen wir daraus? Einfach nur Rust zu verwenden löst keine Performanceprobleme, wenn man Flaschenhälse an völlig anderen Stellen hat. Gerade bei I/O sollte man ein bisschen hinter die Abstraktion schauen und dementsprechend optimieren. Zumindest, wenn man Optimierung braucht.

Genereller betrachtet trifft das auch auf andere Performanceprobleme zu. Zum Beispiel wenn man einen Algorithmus, der eigentlich in linearer Zeit laufen könnte, aus versehen quadratisch macht. Da hilft dann auch keine schnellere Programmiersprache.