[JAVA] Die Geschichte, dass die Standardausgabe auch das Verhalten des Programms tödlich verändert

Ich denke, jeder hat die Erfahrung, Skripten und Programmen, die nicht richtig funktionieren, Standardausgabeverarbeitung ("echo", "System.out.print ()" usw.) hinzuzufügen und sie zu debuggen. Ich denke, dass das Hinzufügen der Standardausgabeverarbeitung in verschiedenen Situationen verwendet wird, von der einfachen Überprüfung des Programmbetriebs bis zur Untersuchung in einer Umgebung, in der ein Debugger aufgrund von Einschränkungen nicht verwendet werden kann.

Das Hinzufügen einer ** 1-zeiligen Standardausgabeverarbeitung kann jedoch auch das Verhalten des Programms ** tödlich verändern.

In der Vergangenheit reagierte die Anwendung als Ergebnis des Hinzufügens einer Zeile "System.out.println (...)" zum Java-Programm, um das Problem zu umgehen, dass der Stapel aufgrund von "Echo" gestoppt wurde. Es gab Zeiten, in denen ich nicht zurückkehren konnte **. Ich möchte den Speicher zu dieser Zeit mit Beispielprogramm erklären.

Die jährliche Charge hat aufgehört!

Vor ungefähr 10 Jahren, eines Tages, erhielt ich eine E-Mail von mir, der für die Wartung eines bestimmten Systems verantwortlich war: "Die jährliche Charge wurde gestoppt. Bitte beeilen Sie sich, dies zu untersuchen." Wenn ich den Text weiter lese, heißt es, dass das Programm in der Zeile der Anweisung "echo" in der Batch-Datei gestoppt wird. s1.png Als ich es zum ersten Mal hörte, bezweifelte ich das Missverständnis des Reporters, aber es ist wahr, dass eine Batch-Datei die folgenden vier aufeinander folgenden Zeilen von "Echo" enthält (Beispiel hier Es gibt k-tamura / stdout-probleme / blob / master / src / main / resources / annual.bat)),

・ ・ ・(Kürzung)・ ・ ・
echo %date% %time% ==================================================>> logs/result.log
echo %date% %time%  [Step4]                                          >> logs/result.log
echo %date% %time%  Pre-Import Processing                            >> logs/result.log
echo %date% %time%                                                   >> logs/result.log
・ ・ ・(Kürzung)・ ・ ・

Als ich das ausgegebene Protokoll (result.log) betrachtete, sah ich nur zwei Zeilen mit echo-Nachrichten.

・ ・ ・(Kürzung)・ ・ ・
2007/09/28 12:04:44.72 ==================================================
2007/09/28 12:04:44.72  [Step4]                                          

(Seitdem wurde kein Protokoll ausgegeben)

Ich dachte, "das ist nicht möglich", aber für den Fall, dass ich mich entschied, eine einfache Testumgebung zu erstellen und die Batch-Datei auszuführen. Das Ergebnis ist wie erwartet. Das Ereignis wurde nicht reproduziert und der Vorgang wurde normal abgeschlossen. Ich konnte mir nichts anderes vorstellen, als den Batch-Prozess von außen zu beenden.

Danach konnte ich den Reporter telefonisch kontaktieren. Als ich die Details hörte, wurde gesagt, dass dieser Stapel von einem Java-Programm aufgerufen wurde.

s2.png

Das Java-Programm, das ich vom Reporter erhalten habe, enthielt die folgende main () -Methode und startete die Batch-Datei mit java.lang.ProcessBuilder ([Beispiel hier](https: //). github.com/k-tamura/stdout-problems/blob/master/src/main/java/org/t246osslab/stdoutproblems/batch/BatchImpl.java)).

import java.io.*;
import org.springframework.core.io.*;

public class BatchImpl implements BatchInterface {

    public static void main(String[] args) {
        System.out.println("Result: " + new BatchImpl().executeBatch());
    }

    public int executeBatch() {
        try {
            Resource resource = new ClassPathResource("annual.bat");
            File batFile = resource.getFile();
            ProcessBuilder pb = new ProcessBuilder(batFile.getAbsolutePath());
            Process process = pb.start();
            return 0;
        } catch (IOException e) {
            e.printStackTrace();
        }
        return -1;
    }
}
* Der Quellcode ist viel einfacher als der eigentliche (zu diesem Zeitpunkt), wobei die Ausnahmebehandlung weggelassen wird, die nichts mit dem Problem dieser Geschichte zu tun hat. ..

Als ich das Java-Programm tatsächlich ausführte, wurde das Phänomen sofort unerwartet reproduziert. Sicherlich wurde die Meldung "Verarbeitung vor dem Import" nicht nach der Meldung "[Schritt 4]" angezeigt.

Also, wenn ich das "Echo" entferne, wird es funktionieren? Ich habe es versucht und es funktioniert gut. Anscheinend tritt ein Ereignis auf, wenn es mehr als eine bestimmte Anzahl von ** Echos gibt **.

Rausfinden

Nachdem bestätigt wurde, dass das Ereignis reproduziert werden kann, wird die Untersuchung gestartet. Nach vielen Recherchen im Internet habe ich eine Ursache gefunden, die wahrscheinlich ist. Das heißt, ** Wenn der vom Java-Programm gestartete Ausgabestream des Prozesses (java.lang.Process) nicht gelesen wird, ist der intern gehaltene Ausgabepuffer voll und der Prozess stoppt **. Das ist.

process_stop.png

Also habe ich eine Codezeile hinzugefügt, die den Ausgabestream mit "Process.getInputStream ()" liest und mit "System.out.println ()" an die Standardausgabe ausgibt.

public int executeBatch() {

    //・ ・ ・(Kürzung)・ ・ ・

    Process process = pb.start();
    System.out.println(IOUtils.toString(process.getInputStream())); //Fügen Sie diese eine Zeile hinzu
    return 0;

    //・ ・ ・(Kürzung)・ ・ ・
}

Die Charge funktionierte dann einwandfrei, ohne anzuhalten. Das Problem, das direkt durch die große Anzahl von Batch-Standardausgabeverarbeitungen ("Echo") verursacht wurde, konnte durch Hinzufügen der Java-Standardausgabeverarbeitung ("System.out.println ()") gelöst werden. Wird sein.

* Um dies ein wenig zu ergänzen, können Sie im Protokoll ausgeben, ohne mit "System.out.println ()" und weiter in die Standardausgabe auszugeben Außerdem wird der Rückgabewert ignoriert, Sie müssen jedoch nur "IOUtils.toString (process.getInputStream ())" hinzufügen.
In Bezug auf das Problem, dass der Ausgabepuffer voll ist, denke ich, dass [diese Seite](https://www.jpcert.or.jp/java-rules/fio07-j.html) leicht zu verstehen ist.

Jetzt, da wir die Ursache kennen, müssen wir überlegen, wie wir damit umgehen sollen, aber wir haben beschlossen, es den "großen Leuten" zu überlassen, die sich in dieser Angelegenheit treffen und nach Hause gehen. Ich dachte: "Dies hat dieses Problem gelöst."

Keine jährliche Chargenantwort!

Als ich am nächsten Tag zur Arbeit ging, gab es einen Bericht, dass "die Antwort der jährlichen Charge nicht zurückkam", den ich gestern hätte korrigieren sollen. s3.png Ist die Korrekturmethode nicht anders? Ich dachte, aber es war nicht anders als ich erwartet hatte.

Und ich habe eine andere neue Tatsache gefunden. Das heißt, ** das Java-Programm und der jährliche Stapel, die wir gestern repariert haben, werden von einer Webanwendung auf einem anderen Host über RMI aufgerufen, wie unten gezeigt **. seq1.png

* RMI (Java Remote Method Invocation): Zur Kommunikation zwischen Java-Programmen über ein Netzwerk und zum Aufrufen von Methoden von Objekten (Remote-Objekten) auf verschiedenen Computern. Technologie.

Die Webanwendung verfügt über einen Bildschirm ähnlich dem, der diesen Stapel aufruft. Wenn Sie auf die Schaltfläche Stapel ausführen klicken, wird RMI verwendet, um den Remote-Stapel asynchron auszuführen. Die Webanwendung zeigt dem Benutzer dann die Meldung "Stapel ausgeführt" an, ohne auf den Abschluss des Stapels zu warten.

Screenshot from 2019-01-28 13-12-19.png

Die Webanwendung sendet dann eine Bestätigungsanforderung für die regelmäßige Fertigstellung. Nach einigen Stunden, in denen der Stapel abgeschlossen ist, antwortet der RMI-Server mit einer Abschlussantwort mit der Meldung "Stapel abgeschlossen".

Screenshot from 2019-01-28 13-12-1987.png

Mit diesem Fix wurde die Meldung "Stapel ausgeführt" jedoch nicht sofort nach dem Klicken auf die Schaltfläche "Stapelausführung" ausgegeben, und es wurde keine Antwort zurückgegeben. wait1.gif (Warten Sie also auf eine solche Antwort im Browser wurde) Angesichts dieser neuen Tatsache und der Änderungen, die wir gestern vorgenommen haben, dauerte es nicht lange, die Ursache herauszufinden.

Vor dem Hinzufügen einer Zeile von "System.out.println (・ ・ ・);" gab das Java-Programm (= vom RMI-Server aufgerufene Java-Modul) sofort eine Antwort zurück, aber nach dem Hinzufügen Das Java-Programm sollte eine Antwort zurückgeben, nachdem es auf den Abschluss des Stapels gewartet hatte. Der Grund dafür ist, dass ** Java-Programme jetzt synchron mit dem Stapel ausgeführt werden, indem von Zeit zu Zeit die Standardausgabe des Stapels gelesen wird **.

seq2.png

Diesmal gibt es kein Problem

Was ist dann zu tun?

Da die Ausgabemenge von "Echo" in der Batch-Datei groß ist, wird das Reduzieren von "Echo" auch als vorläufiger Plan angesehen. Dies ist auch eine der richtigen Optionen, da es ein dringendes Problem ist, es zu beheben, aber keine Protokollierung ist nicht sehr gut. Darüber hinaus möchte ich Maßnahmen ergreifen, die die Zukunft nach Möglichkeit berücksichtigen, wobei die Mindestkorrektur die Verschlechterung berücksichtigt (jemand kann zum Zwecke des Debuggens "Echo" hinzufügen usw.). Da gibt es keine). s4.png Als ich darüber nachdachte, wie ich etwas Gutes tun könnte, war die Schlussfolgerung einfach. ** Fügen Sie die folgende Zeile am Anfang der Batch-Datei hinzu **.

@echo off

Mit anderen Worten, ich hätte verhindern sollen, dass der Stapel in die Standardausgabe ausgegeben wird.

Wie Sie sehen können, indem Sie die Batchdatei an der Eingabeaufforderung ausführen, sind die Informationen (= Standardausgabe), die an der Eingabeaufforderung nach der Ausführung angezeigt werden, ** nur der ausgeführte Befehl **, wie unten gezeigt.

C:\batch>mkdir logs

C:\batch>echo 2007/09/28 12:04:44.72 ==================================================>> logs/result.log

C:\batch>echo 2007/09/28 12:04:44.73  [Start]                                          >> logs/result.log

C:\batch>echo 2007/09/28 12:04:44.74                                                   >> logs/result.log

C:\batch>echo 2007/09/28 12:04:44.75  Initialize                                      >>logs/result.log

・ ・ ・ (Unten weggelassen) ・ ・ ・

Alle Informationen, die der Stapel ausgeben möchte, werden in die Protokolldatei (>> logs / result.log) umgeleitet, und die Standardausgabe ist eine unnötige Information.

5.png

* Informationen zum Betrieb von "@ echo off" finden Sie unter [Diese Seite](https://www.adminweb.jp/command/bat/index2.html). Ich denke, die Erklärung ist leicht zu verstehen.

Also habe ich am Anfang der Batch-Datei "@echo off" hinzugefügt, überprüft, dass es kein Problem gibt, und die Gegenmaßnahme wurde vorerst abgeschlossen. s5.png

* Die Implementierung des oben vorgestellten Java-Programms bedeutet nicht, dass kein Raum für eine Überprüfung vorhanden ist.

Es gibt eine Überlegung, dass die Untersuchung aller Anrufer des korrigierten Teils weggelassen wurde, aber es war ein Ereignis, bei dem ich dachte, dass es schwierig sein würde, einen Fehler zu beheben, der dringend Maßnahmen erfordert. Und es war eine seltene Erfahrung, dass ich die Standardausgabe als Gegenmaßnahme für den Fall verwendete, dass die Standardausgabe zu einem Problem wurde, und es gab dort auch ein anderes Problem.

Schließlich

Es ist möglicherweise besser zu bedenken, dass "eine Codezeile, die auf den ersten Blick keine nachteiligen Auswirkungen zu haben scheint, wie die Standardausgabeverarbeitung, das Verhalten des Programms tödlich verändern kann". Vielleicht.

[Ergänzung] Eigentlich versuchen

Ich habe ein [Beispielprogramm] erstellt (https://github.com/k-tamura/stdout-problems/blob/master/README.md). Wenn Sie also interessiert sind, versuchen Sie es bitte. Ich habe es basierend auf Spring Boot gemacht, basierend auf der Erinnerung von vor ungefähr 10 Jahren. Der Anwendungsserver und der RMI-Server befinden sich auf demselben Host und sind für die Kommunikation über localhost ausgelegt.

Da es sich um eine Betriebsprüfung handelt, ist der Prozess zum Erkennen des Abschlusses des Stapels durch die Webanwendung nicht implementiert. Darüber hinaus wird die Stapelverarbeitung wie der DB-Zugriff nicht geschrieben, und die Stapeloperation wird pseudo-reproduziert, indem für einen bestimmten Zeitraum in den Ruhezustand versetzt wird.

Referenzmaterial

cci95logo.gif

Recommended Posts