Veröffentlicht am von Maximilian

mtail testen mit Golden Files

Wie wir bereits beschrieben haben, benutzen wir mtail um Prometheus-Metrics aus Logs zu erzeugen. 

mtail-Programme enthalten Patterns für konkrete Logzeilen, aus denen die Metrics entstehen.

Wie alle Programme können solche für mtail natürlich auch Fehler enthalten. Deswegen wollen wir dafür gerne, wie für andere Programme auch, automatische Tests haben. Dann können wir mindestens bekannte Fehler ausschließen. Tests schaffen auch Sicherheit bei Refactorings, dass man keine Funktionalität kaputt gemacht hat durch Änderungen.

mtail hat keine eingebaute Funktionalität für Testcases. Es hat aber das Flag -one_shot, um es nur einmalig auszuführen, und die Ergebnisse eines Logfiles auszugeben:

mtail -one_shot -one_shot_format prometheus -progs files/puppetserver.mtail -logs testdata/input/puppetserver.log

Das erzeugt diese Ausgabe der Metrics im Prometheus-Format:

# HELP puppetserver_enc_timeouts_total defined at puppetserver.mtail:32:9-39
# TYPE puppetserver_enc_timeouts_total counter
puppetserver_enc_timeouts_total{prog="puppetserver.mtail"} 0
# HELP puppetserver_jruby_instances_created_total defined at puppetserver.mtail:34:9-50
# TYPE puppetserver_jruby_instances_created_total counter
puppetserver_jruby_instances_created_total{prog="puppetserver.mtail"} 1
# HELP puppetserver_jruby_instances_flushed_total defined at puppetserver.mtail:35:9-50
# TYPE puppetserver_jruby_instances_flushed_total counter
puppetserver_jruby_instances_flushed_total{prog="puppetserver.mtail"} 0
# HELP puppetserver_puppetdb_commands_total defined at puppetserver.mtail:33:9-44
# TYPE puppetserver_puppetdb_commands_total counter
puppetserver_puppetdb_commands_total{command="replace_catalog",prog="puppetserver.mtail"} 1
puppetserver_puppetdb_commands_total{command="replace_facts",prog="puppetserver.mtail"} 3
puppetserver_puppetdb_commands_total{command="store_report",prog="puppetserver.mtail"} 3

Jetzt haben wir ein Ergebnis von mtail. Aber wie testen wir das?

Ein einfacher Ansatz text-basierte Ergebnisse zu testen sind sogenannte Golden Files (auch bekannt als Snapshot Testing). Das Golden File enthält dabei das Soll-Ergebnis. Der Test vergleicht das Ist-Ergebnis mit diesem Soll-Ergebnis. Wenn es Abweichungen gibt, failt der Test. Bei absichtlichen Änderungen kann man den Diff der beiden Dateien ansehen, und wenn alles in Ordnung ist, das Soll-Ergebnis aktualisieren.

Zwei Textdateien können wir mit dem Standard-UNIX-Command diff vergleichen. diff returnt den Exitcode 0 wenn es keine Unterschiede gibt, und 1 wenn es welche gibt.

Um das ganze in unsere Pipelines zu integrieren, machen wir das in Earthly:

VERSION 0.8

test:
	BUILD +golden-puppetserver

golden-puppetserver:
	FROM +deps
	COPY files/puppetserver.mtail testdata/input/puppetserver*.log .
	# das grep entfernt die HELP-Zeilen, weil diese die Zeilenummern im Sourcecode enthalten, und unnötig abweichen würden bei Änderungen.
	RUN mtail -progs puppetserver.mtail -logs puppetserver.log -logs puppetserver-access.log -one_shot -one_shot_format prometheus | grep -v '^# HELP'> got.prom
	COPY testdata/want/puppetserver.prom want.prom
	RUN diff -u want.prom got.prom

deps:
	FROM debian:12@sha256:b8084b1a576c5504a031936e1132574f4ce1d6cc7130bbcc25a28f074539ae6b
	RUN apt-get update
	RUN apt-get install --no-install-recommends -y mtail

Earthly bricht automatisch ab, wenn ein RUN-Befehl nicht mit Exitcode 0 returnt.

$ earthly +test
 […]
+golden-puppetserver *failed* | Repeating the failure error...
+golden-puppetserver *failed* | --> RUN diff -u want.prom got.prom
+golden-puppetserver *failed* | --- want.prom   2020-04-16 12:00:00.000000000 +0000
+golden-puppetserver *failed* | +++ got.prom    2024-09-16 11:49:19.303344010 +0000
+golden-puppetserver *failed* | @@ -57,7 +57,7 @@
[…]
+puppetserver_jruby_borrow_seconds_bucket{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail",le="4"} 0
+golden-puppetserver *failed* | +puppetserver_jruby_borrow_seconds_bucket{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail",le="5"} 0
+golden-puppetserver *failed* | +puppetserver_jruby_borrow_seconds_bucket{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail",le="6"} 0
+golden-puppetserver *failed* | +puppetserver_jruby_borrow_seconds_bucket{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail",le="7"} 0
[…]
+puppetserver_jruby_borrow_seconds_sum{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail"} 0
+golden-puppetserver *failed* |  puppetserver_jruby_borrow_seconds_count{endpoint="/puppet/v3/file_metadatas",prog="puppetserver.mtail"} 2
+golden-puppetserver *failed* |  # TYPE puppetserver_jruby_instances_created_total counter
+golden-puppetserver *failed* | ERROR Earthfile:12:1
+golden-puppetserver *failed* |       The command
+golden-puppetserver *failed* |           RUN diff -u want.prom got.prom
+golden-puppetserver *failed* |       did not complete successfully. Exit code

Ein Nachteil von Golden Files ist, dass immer die gesamte Ausgabe 1:1 verglichen wird. D.h. die Tests failen auch bei Änderungen, die eigentlich gar nichts kaputt gemacht machen. Bei mtail steht sogar die jeweilige Zeilennummer, an der eine Metric definiert wird, in der Ausgabe – deswegen haben wir im Earthfile ein grep, das wenigstens diese Zeilen ausfiltert.

Ein robusterer Test wäre z.B. dass man das mtail-Ergebnis mit einem Go-Programm einliest und dann konkrete Assertions auf einzelne Metrics schreibt. Das wäre allerdings schon deutlich aufwändiger. Die Golden Files sind hier ein akzeptabler Kompromiss zwischen Test-Aufwand und -Nutzen.

Wenn du auch Interesse hast Tests zu erstellen, schau dir doch mal unsere Stellenangebote an 🙂

(Header-Bild: High Contrast, CC BY 3.0 DE, via Wikimedia Commons)