System.out.println and System.err.println out of order

System.out.println и System.err.println вышли из строя

Мои вызовы System.out.println() и System.err.println() выводятся на консоль не в том порядке, в котором я их выполняю.

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

Это приводит к:

out
out
out
out
out
err
err
err
err
err

Вместо чередования out и err. Почему это?

Переведено автоматически

Ответ 1

Это разные потоки, и они сбрасываются в разное время.

Если вы поставите

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

внутри вашего цикла все будет работать так, как ожидалось.

Чтобы уточнить, выходные потоки кэшируются, поэтому вся запись поступает в этот буфер памяти. После периода затишья они фактически записываются.

Вы выполняете запись в два буфера, затем после периода бездействия они оба очищаются (один за другим).

Ответ 2

Это вызвано функцией в JVM, и если вы не сделаете взлом, подобный тому, который предоставил Маркус А., обойти это не так-то просто. В этом случае .flush() работает, но обойти причину этого намного сложнее.

Что здесь происходит?

Когда вы программируете на Java, вы не говорите компьютеру напрямую, что делать, вы сообщаете JVM (виртуальной машине Java), что бы вы хотели, чтобы она делала. И он сделает это, но более эффективным способом. Ваш код не содержит точных подробных инструкций, в этом случае вам понадобится только компилятор, подобный C и C ++, JVM принимает ваш код как список спецификаций того, что он должен оптимизировать, а затем выполняет. Вот что здесь происходит. Java видит, что вы помещаете строки в два разных потока буфера. Наиболее эффективный способ сделать это - буферизировать все строки, которые вы хотите, чтобы потоки выводили, а затем вывести это. Это происходит по одному потоку за раз, существенно преобразуя ваш код, сделайте что-то вроде этого (осторожно: псевдокод):

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

Поскольку это более эффективно, это то, что JVM будет делать вместо этого. Добавление .flush() в цикл будет сигнализировать JVM о том, что в каждом цикле необходимо выполнить сброс, что невозможно улучшить с помощью описанного выше метода. Но если вы ради объяснения того, как это работает, пропустили бы цикл, JVM изменит порядок вашего кода, чтобы печать выполнялась последней, потому что это более эффективно.

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();

Этот код всегда будет реорганизован примерно так:

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

Потому что буферизация многих буферов только для того, чтобы сразу же их очистить, занимает намного больше времени, чем буферизация всего кода, подлежащего буферизации, а затем очистка всего этого одновременно.

Как это решить

Вот тут-то и могут вступить в игру проектирование кода и архитектура; вы как бы не решаете эту проблему. Чтобы обойти это, вы должны сделать более эффективным буферизацию печати / сброса, буферизацию печати / сброса, чем буферизацию всего, а затем сброс. Это, скорее всего, привлечет вас к плохому дизайну. Если для вас важно, как упорядоченно выводить данные, я предлагаю вам попробовать другой подход. Зацикливание с помощью .flush() - это один из способов взломать его, но вы все равно взламываете функцию JVM, чтобы переупорядочить и оптимизировать ваш код для вас.

* Я не могу проверить, что буфер, который вы добавили в first, всегда будет печататься первым, но, скорее всего, так и будет.

Ответ 3

Если вы используете консоль Eclipse, похоже, что работают два разных явления:
одно, как описано @Gemtastic, это обработка потоков JVMS, а другое - способ, которым Eclipse считывает эти потоки, как упомянуто @DraganBozanovic. Поскольку я использую Eclipse, элегантного flush()решения, опубликованного @BillK, которое решает только проблему с JVM, недостаточно.

В итоге я написал вспомогательный класс под названием EclipseTools со следующим содержимым (и требуемым объявлением пакета и импортом). Это немного взлом, но устраняет обе проблемы:

public class EclipseTools {

    private static List<OutputStream> 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<OutputStream>();
        System.setErr(new PrintStream(new FixedStream(System.err)));
        System.setOut(new PrintStream(new FixedStream(System.out)));
    }
}

Для использования просто вызовите EclipseTools.fixConsole() один раз в начале вашего кода.

По сути, это заменяет два потока System.err и System.out пользовательским набором потоков, которые просто пересылают свои данные в исходные потоки, но отслеживают, какой поток был записан последним. Если поток, в который записывается, изменяется, например, a, за которым System.err.something(...) следует a System.out.something(...), вывод последнего потока сбрасывается и ожидает 200 мс, чтобы дать консоли Eclipse время завершить его печать.

Примечание: 200 мс - это всего лишь приблизительное начальное значение. Если этот код уменьшает, но не устраняет проблему для вас, увеличьте задержку в Thread.sleep с 200 до чего-то большего, пока это не сработает. В качестве альтернативы, если эта задержка работает, но влияет на производительность вашего кода (если вы часто чередуете потоки), вы можете попробовать постепенно уменьшать ее, пока не начнете получать ошибки.

Ответ 4

Два оператора println обрабатываются двумя разными потоками. Результат опять же зависит от того, в какой среде вы запускаете код. Например, я выполнил следующий код в IntelliJ и командной строке по 5 раз каждый.

public class Test {
    public static void main(String[] args) {
        for (int i = 0; i < 10; i++) {
            System.out.print("OUT ");
            System.err.print("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 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

Я предполагаю, что разные среды обрабатывают буферы по-разному.

Один из способов увидеть, что эти потоки фактически обрабатываются разными потоками, - это добавить sleep оператор в цикл. Вы можете попробовать изменить значение, которое вы установили для режима ожидания, и увидите, что фактически они обрабатываются разными потоками.

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();
            }
        }
    }
}

Результат в этом случае оказался следующим

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

Один из способов заставить его печатать в том же порядке - использовать .flush(), который сработал у меня. Но, похоже, не все получают с его помощью правильные результаты.

Два потока, обрабатываемые двумя разными потоками, вероятно, являются причиной, по которой мы иногда видим, что ERROR сообщение, напечатанное некоторыми библиотеками, которые мы используем, печатается перед некоторыми операторами печати, которые мы должны были видеть в соответствии с порядком выполнения.