Logging und Tracing mit Kontextinformation fĂĽr Java-Entwickler
Seite 3: Zipkin Server und Tools
Funktionen des Zipkin-Servers
Aber der Zipkin-Server kann noch mehr: Er speichert die Trace- und Span-Informationen inklusive Timing-Daten zentral und erstellt gleichzeitig eine Übersicht über die Servicelandschaft. So lassen sich beispielsweise Einträge suchen, die Fehler produzierten oder besonders lange brauchten. Das System sammelt die Informationen separat von den eigentlichen Logs der Anwendungen. In Produktion wird in der Regel nur ein kleiner Prozentsatz dieser Daten erfasst, um unnötig große Sammlungen zu vermeiden.
Der Zipkin-Server besteht aus einem Web-Frontend, einer Serveranwendung und einem Backend, um die Daten zu speichern (entweder Cassandra, MySQL oder Elasticsearch). Das Web-Frontend stellt die Beziehung der Services untereinander dar und zeigt pro Request eine detaillierte serviceĂĽbergreifende Zeitleiste an
Traces enthalten automatisch querschnittliche Informationen wie den Servicename und die aufgerufene URL. Dafür ist kein fachlicher Code anzupassen. Sind mehr Informationen in den Traces gewünscht, können Entwickler den Traces im fachlichen Code Tags und Events hinzufügen. Die Daten sind dann für die Suche und die Anzeige in Zipkin verfügbar.
@Component
public class BillingResource {
@Autowired
private Tracer tracer;
public String startBillingRun() {
/* ... */
Span span = tracer.getCurrentSpan();
span.logEvent("log a line");
tracer.addTag("invoiceId", String.valueOf(i.getId()));
/* ... */
}
}
Zipkin-Werkzeuge nicht nur fĂĽr Entwickler
Ein Service erstellt immer dann eine neue Trace-ID, wenn der empfangene Request keine enthält. Den Umstand nutzt Chromes Zipkin Plugin: Es erzeugt die Trace-ID im Browser und schickt sie mit dem Request zum Server. So ist die ID im Vorhinein bekannt und das Plug-in kann für die Analyse direkt aus den Chrome-Entwicklerwerkzeugen in den passenden Trace im Zipkin-Web-Frontend verlinken. Eine aufwendige Suche entfällt. Außerdem setzt es den X-B3-Sampled-Header: Er stellt sicher, dass der Trace protokolliert wird und zum Zipkin-Server gelangt – unabhängig von der Anwendungskonfiguration. Sleuth leitet diesen Header auch an alle nachgelagerten Services weiter, sodass alle Abschnitte des Aufrufbaums protokolliert werden.
Dieses Vorgehen lässt sich nicht nur in den Entwicklungsumgebungen, sondern auch in Produktion nutzen, um einzelne Traces zu sammeln – insbesondere, wenn in Produktion aus Performancegründen normalerweise nur ein kleiner Prozentsatz gespeichert wird.
Ist das Plug-in aktiviert, sendet es die zusätzlichen HTTP-Header für alle Requests mit. Daher sollten es Entwickler ausschalten, wenn sie die Funktion nicht benötigen. Darüber hinaus ist es naheliegend, alle X-B3-*-HTTP-Header an der äußeren Firewall zu entfernen, um zu verhindern, dass jemand von außerhalb des Unternehmens die Header mitschickt und so unnötig oder mutwillig Logs- und Trace-Informationen generiert.
Per-Request-Debugging mit log4j2 and Zipkin
Mit den zusätzlichen HTTP-Headern lassen sich Trace-Informationen in Produktion sammeln, während Logs meist nur Warnungen und Fehler protokollieren. Log4j 2.x enthält eine Lösung dafür: Zipkin und Sleuth verarbeiten zusätzlich den Header X-B3-Flags, wobei der Wert 1 für "Debugging angestellt" steht. An diese Information kommen Anwender mit einem Filter analog zu dem für die Nutzerdaten aus dem anfänglichen Beispiel, dass sie im MDC mit dem Schlüssel X-B3-Flags-debug ablegt. Die folgende Konfiguration von DynamicThresholdFilter in log4j2.xml erwirkt das Anlegen von Log-Einträgen im Trace-Level für jeden Request, der mit dem X-B3-Flags-Header und dem Wert 1 an die Anwendung geschickt wurde.
<DynamicThresholdFilter key="X-B3-Flags-debug" onMatch="ACCEPT"
defaultThreshold="warn" onMismatch="NEUTRAL">
<KeyValuePair key="true" value="trace"/>
</DynamicThresholdFilter>
Das klappt jedoch erst ab log4j Version 2.7 zuverlässig: Frühere Varianten enthalten einen Fehler, der verhinderte, dass der Vorgang für Log-Meldungen mit Parametern funktionierte (vgl. Ticket LOG4J2-1511).