Java: System.out.println y System.err.println fuera de servicio

Mis llamadas a System.out.println() y System.err.println() no se están imprimiendo en la consola en el orden en que las realizo.

 public static void main(String[] args) { for (int i = 0; i < 5; i++) { System.out.println("out"); System.err.println("err"); } } 

Esto produce:

 out out out out out err err err err err 

En lugar de alternar y err . ¿Por qué es esto?

Son streams diferentes y se lavan en diferentes momentos.

Si pones

 System.out.flush(); System.err.flush(); 

dentro de tu ciclo, funcionará como se espera.

Para aclarar, las transmisiones de salida se almacenan en la memoria caché para que toda la escritura entre en este búfer de memoria. Después de un período de silencio, en realidad están escritos.

Usted escribe en dos memorias intermedias, luego de un período de inactividad ambos se lavan (uno después del otro).

Esto es causado por una característica en la JVM y, a menos que realice un hack tal como el provisto por Marcus A. , no es realmente tan fácil de solucionar. The .flush() funciona en este caso, pero la razón de esto es mucho más complicada.

¿Que está sucediendo aquí?

Cuando progtwig en Java no le está diciendo directamente a la computadora qué hacer, le está diciendo a la JVM (Máquina Virtual de Java) lo que le gustaría que hiciera. Y lo hará, pero de una manera más eficiente. Su código no es instrucciones detalladas exactas, en ese caso solo necesitaría un comstackdor como C y C ++, la JVM toma su código como una lista de especificaciones para lo que se supone que debe optimizar y luego hacer. Esto es lo que está pasando aquí . Java ve que está presionando cadenas en dos flujos de buffer diferentes. La forma más eficiente de hacerlo es almacenar en el búfer todas las cadenas que desea que emitan las secuencias y luego emitirlas. Esto sucede una secuencia en el momento, esencialmente transformando tu código haz algo como esto (cuidado: pseudo código) :

 for(int i = 0; i < 5; i++) { out.add(); err.add(); } out.flush(); err.flush(); 

Como esto es más eficiente, esto es lo que hará la JVM en su lugar. Agregar el .flush() en el bucle le indicará a la JVM que es necesario realizar un enjuague en cada bucle, que no se puede mejorar con el método anterior. Pero si por el mero hecho de explicar cómo funciona esto habría dejado de lado el ciclo, la JVM volverá a ordenar el código para que la impresión finalice, porque es más eficiente.

 System.out.println("out"); System.out.flush(); System.err.println("err"); System.err.flush(); System.out.println("out"); System.out.flush(); System.err.println("err"); System.err.flush(); 

Este código siempre se reorganizará a algo como esto:

 System.out.println("out");* System.err.println("err");* System.out.println("out");* System.err.println("err");* System.out.flush(); System.err.flush(); 

Debido a que el almacenamiento en búfer de muchos búferes solo para descargarlos inmediatamente lleva mucho más tiempo que almacenar todo el código que se almacenará en el búfer y luego eliminarlo todo al mismo tiempo.

Cómo resolverlo

Aquí es donde el diseño de código y la architecture pueden entrar en juego; usted no puede resolver esto. Para evitar esto, tiene que hacer que sea más eficiente almacenar en búfer la impresión / el color, el búfer imprimir / enjuagar que el búfer todo y luego al ras. Es muy probable que esto lo atraiga hacia un mal diseño. Si es importante para usted cómo enviarlo ordenadamente, le sugiero que pruebe un enfoque diferente. For-looping con .flush() es una forma de hackearlo, pero aún está pirateando la función de la JVM para reorganizar y optimizar su código.

* No puedo verificar que el buffer que agregaste primero siempre se imprima primero, pero lo más probable es que lo haga.

Si está utilizando la consola Eclipse, parece que hay dos fenómenos diferentes en el trabajo:
Uno, como lo describe @Gemtastic , es el manejo de las transmisiones por las JVM y el otro es la forma en que Eclipse lee estas transmisiones, como lo menciona @DraganBozanovic . Como uso Eclipse, la solución elegante flush() publicada por @BillK , que solo soluciona el problema de JVM, no es suficiente.

Terminé escribiéndome una clase de ayuda llamada EclipseTools con el siguiente contenido (y la statement e importación del paquete requerido). Es un truco pero soluciona ambos problemas:

 public class EclipseTools { private static List streams = null; private static OutputStream lastStream = null; private static class FixedStream extends OutputStream { private final OutputStream target; public FixedStream(OutputStream originalStream) { target = originalStream; streams.add(this); } @Override public void write(int b) throws IOException { if (lastStream!=this) swap(); target.write(b); } @Override public void write(byte[] b) throws IOException { if (lastStream!=this) swap(); target.write(b); } @Override public void write(byte[] b, int off, int len) throws IOException { if (lastStream!=this) swap(); target.write(b, off, len); } private void swap() throws IOException { if (lastStream!=null) { lastStream.flush(); try { Thread.sleep(200); } catch (InterruptedException e) {} } lastStream = this; } @Override public void close() throws IOException { target.close(); } @Override public void flush() throws IOException { target.flush(); } } /** * Inserts a 200ms delay into the System.err or System.out OutputStreams * every time the output switches from one to the other. This prevents * the Eclipse console from showing the output of the two streams out of * order. This function only needs to be called once. */ public static void fixConsole() { if (streams!=null) return; streams = new ArrayList(); System.setErr(new PrintStream(new FixedStream(System.err))); System.setOut(new PrintStream(new FixedStream(System.out))); } } 

Para usar, simplemente llame a EclipseTools.fixConsole() una vez al comienzo de su código.

Básicamente, esto reemplaza las dos secuencias System.err y System.out con un conjunto personalizado de secuencias que simplemente reenvían sus datos a las secuencias originales, pero realiza un seguimiento de la secuencia que se escribió para durar. Si el flujo que se escribe en los cambios, por ejemplo, System.err.something(...) seguido de un System.out.something(...) , vacía el resultado del último flujo y espera 200 ms para dar el tiempo de la consola Eclipse para completar la impresión.

Nota: Los 200 ms son solo un valor inicial aproximado. Si este código reduce, pero no elimina el problema para usted, aumente el retraso en Thread.sleep de 200 a algo más alto hasta que funcione. Alternativamente, si este retraso funciona pero afecta el rendimiento de tu código (si alternas las transmisiones a menudo), puedes intentar reducirlo gradualmente hasta que comiences a recibir errores.

Este es un error en Eclipse . Parece que Eclipse usa hilos separados para leer el contenido de out streams de out y err sin ninguna sincronización.

Si comstack la clase y la ejecuta en la consola (con el clásico java

), el orden es el esperado.

Las dos instrucciones println son manejadas por dos hilos diferentes. La salida nuevamente depende de en qué entorno está ejecutando el código. Por ejemplo, ejecuté el siguiente código en IntelliJ y en la línea de comandos 5 veces cada uno.

 public class Test { public static void main(String[] args) { for (int i = 0; i < 10; i++) { System.out.print("OUT "); System.err.print("ERR "); } } } 

Esto resulta en el siguiente resultado:
Línea de comando

 OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR OUT ERR 

IntelliJ:

 ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT OUT ERR ERR ERR ERR ERR ERR ERR ERR ERR ERR 

Supongo que diferentes entornos manejan los búferes de manera diferente.
Una forma de ver que estas secuencias de datos son manejadas por diferentes hilos es agregar una instrucción sleep en el ciclo. Puede intentar variar el valor que establece para el sueño y ver que estos son de hecho manejados por diferentes hilos.

 public class Test { public static void main(String[] args) { for (int i = 0; i < 10; i++) { System.out.print("OUT "); System.err.print("ERR "); try { Thread.sleep(500); } catch (InterruptedException e) { e.printStackTrace(); } } } } 

La salida en este caso resultó ser

 OUT ERR ERR OUT ERR OUT OUT ERR OUT ERR ERR OUT OUT ERR ERR OUT OUT ERR OUT ERR OUT ERR ERR OUT ERR OUT OUT ERR OUT ERR ERR OUT OUT ERR ERR OUT OUT ERR OUT ERR ERR OUT ERR OUT OUT ERR ERR OUT OUT ERR ERR OUT OUT ERR OUT ERR ERR OUT ERR OUT ERR OUT OUT ERR ERR OUT OUT ERR ERR OUT ERR OUT OUT ERR ERR OUT ERR OUT OUT ERR OUT ERR OUT ERR ERR OUT OUT ERR ERR OUT OUT ERR ERR OUT ERR OUT OUT ERR OUT ERR 

Una forma de obligarlo a imprimirlo en el mismo orden sería utilizar .flush() , que funcionó para mí. Pero parece que no todos obtienen los resultados correctos con eso.

Las dos secuencias manejadas por 2 dos hilos diferentes es probablemente la razón por la que a veces vemos el mensaje ERROR impreso por algunas bibliotecas que usamos, imprimiéndolo antes de algunas declaraciones impresas que se suponía que veríamos de acuerdo con el orden de ejecución.

He usado hilo para imprimir la salida de System.out y System.err secuencialmente como:

  for(int i = 0; i< 5; i++){ try { Thread.sleep(100); System.out.print("OUT"); Thread.sleep(100); System.err.print("ERR"); }catch (InterruptedException ex){ System.out.println(ex.getMessage()); } }