„Bösewicht“ System.out

23.11.2020

Es dürfte ja allgemein bekannt sein, dass System.out.println(…)-Statements in Java-Programmen vermieden werden sollen. Stattdessen verwendet man ein Logging-Framework mit dem konfigurativ und feingranular gesteuert werden kann, welche Ausgaben wohin geschrieben werden.

Was aber, wenn eine Komponente verwendet werden muss, auf deren Sourcecode man keinen Einfluss hat, und die genau sowas macht, also nach System.out schreibt?!? Welche Folgen das haben kann und wie ein Workaround aussehen könnte, der Ausgaben nach Standard-Out (stdout) unterbindet, beschreibe ich im Folgenden.

System.out führte zu Produktiv-Incident

Diesen Fall hatten wir kürzlich in einem Projekt, in dem  eine Komponente in Form einer .jar-Datei benötigt wird, auf deren Quellcode wir keinen Zugriff haben. Aufgrund einer unglücklichen Konstellation schrieb die Bibliothek Gigabytes an Nachrichten nach System.out; diese landeten schließlich auf dem Produktivsystem in /var/log/messages und sorgten dafür, dass das Dateisystem des Hosts voll lief.

Nun könnte man beim Start der Anwendung alle stdout-Ausgaben nach /dev/null umleiten; das hat aber den Nachteil, dass damit eventuelle OS-seitige Ausgaben ebenfalls verschluckt werden.

Der Workaround

Unsere Lösung, oder eher Workaround, war der folgende:

import java.io.PrintStream;
import org.apache.commons.io.output.NullOutputStream;
// ... (weitere Imports)
 
@Order(0)
@Component
class SystemOutDeactivator implements ApplicationListener<ApplicationReadyEvent> {
 
    private static final Logger LOG = LogManager.getLogger(SystemOutDeactivator.class);
 
    /**
     * Event handler method for the {@link ApplicationReadyEvent}. Replaces System.out with a no-op PrintStream.
     * @param event the {@link ApplicationReadyEvent}.
     */
    @Override
    public void onApplicationEvent(ApplicationReadyEvent event) {
        LOG.info("About to disable System.out, to prevent uncontrolled writes from the ComponentWritingToSystemOut to stdout...");
 
        System.setOut(new PrintStream(new NullOutputStream()));
 
        LOG.info("Done... all writes to System.out will now be ignored.");
    }
}

Da wir Spring Boot verwenden, haben wir das Ganze als ApplicationListener für den ApplicationReady-Event implementiert, der beim Start der SpringBoot-Anwendung aufgerufen wird.

Das entscheidende Stück Code steht in Zeile 19 → ja, man kann das Objekt, das sich hinter System.out verbirgt tatsächlich ersetzen, und zwar mit der Methode System.setOut(…). Hierfür verwenden wir einen NullOutputStream der apache-commons-io-Bibliothek, der alle dort hineingeschriebenen Daten einfach ignoriert. Sollte dies der einzige Grund sein für den die Bibliothek benötigt wird, kann man stattdessen einen entsprechenden NullOutputStream auch ganz einfach selbst implementieren, nämlich mit einer Klasse die von OutputStream erbt und alle Methoden mit leerem Methodenkörper überschreibt.

Das Schöne an dieser Lösung ist, dass man nach wie vor einen Log4J-ConsoleAppender verwenden kann. Das ist der Implementierung des ConsoleAppenders geschuldet sowie der Tatsache, dass SpringBoot das Logging initialisiert, bevor unsere onApplicationEvent(…)-Methode aufgerufen wird. Denn der ConsoleAppender schreibt selbst nicht direkt nach System.out, sondern in einen eigenen OutputStream, der als Wrapper um System.out fungiert. Und da der Wrapper-OutputStream vor dem Aufruf unserer Methode erzeugt wird, bekommt er noch das ursprüngliche System.out-Objekt, das nach stdout schreibt.

Der Nachteil daran ist, dass eventuell nützliche Ausgaben der Komponente nach System.out nun verloren gehen.

Das Resultat

Schreiben mit LOG.info(„some log message“); unter Verwendung eines ConsoleAppenders landet in stdout
Schreiben nach System.out wie z.B. System.out.println(„Don’t try this at work!“); landet im „Nirwana“!

Coole Sache, oder?

Zurück zur Übersicht

Kommentar verfassen

Deine E-Mail-Adresse wird nicht veröffentlicht. Erforderliche Felder sind mit * markiert

*Pflichtfelder

*