У меня есть приложение, которое объединяет все свои журналы в класс одного экземпляра, чтобы упростить выборочную отладочную печать и т. Д. Класс работает около года или около того, работает без сбоев, но совсем недавно мне довелось перевернуть журнал уровень до самого высокого значения (что я редко делаю), и стандартный вывод , кажется, в конечном итоге блокирует . Это вызывает хаос в следующий раз, когда какая-то другая часть кода вызывает println, или когда он пытается использовать класс ведения журнала (который заблокирован в ожидании возврата println).
Сначала я подумал, что у меня возникла какая-то проблема параллелизма с моим классом журналирования, но очистка трассировки стека заверяет меня, что моя синхронизация работает правильно и что только один поток пытается записать данные в консоль в любой момент времени. , Вот пример трассировки стека в потоке-нарушителе:
Thread [Thread-127] (Suspended)
FileOutputStream.writeBytes(byte[], int, int) line: not available [native method] [local variables unavailable]
FileOutputStream.write(byte[], int, int) line: 260
BufferedOutputStream.flushBuffer() line: 65
BufferedOutputStream.flush() line: 123
PrintStream.write(byte[], int, int) line: 432
StreamEncoder.writeBytes() line: 202
StreamEncoder.implFlushBuffer() line: 272
StreamEncoder.flushBuffer() line: 85
OutputStreamWriter.flushBuffer() line: 168
PrintStream.write(String) line: 477
PrintStream.print(String) line: 619
PrintStream.println(String) line: 756
Logger(Logger).LogMessage(String) line: 180
RemoteConsoleMonitor$1.run() line: 56
Thread.run() line: 662
Покопавшись немного глубже в собственных трассировках стека, я обнаружил, что процесс JVM блокирует собственный вызов ZwWriteFile Windows. Мое лучшее предположение - то, что JVM использует именованные каналы, настроенные для синхронного чтения / записи буферизованных данных, но что считыватель каким-то образом остановился и позволил заполнить буфер. Между тем, писатель блокируется, ожидая, пока освободится буферное пространство, но этого никогда не происходит. Вот собственная трассировка стека того же потока:
ntdll.dll!_ZwWriteFile@36() + 0x15 bytes
ntdll.dll!_ZwWriteFile@36() + 0x15 bytes
jvm.dll!InterfaceSupport::serialize_memory(JavaThread * thread=0x00000220) Line 40 + 0x9 bytes C++
java.dll!writeBytes(const JNINativeInterface_ * * env=0x2ac2b13c, _jobject * this=0x3e00f204, _jobject * bytes=0x3e00f200, long off=0, long len=97, _jfieldID * fid=0x7ecee033) Line 144 + 0x21 bytes C
java.dll!Java_java_io_FileOutputStream_writeBytes(const JNINativeInterface_ * * env=0x2ac2b13c, _jobject * this=0x3e00f204, _jobject * bytes=0x3e00f200, long off=0, long len=97) Line 73 + 0x20 bytes C
0d8a3826()
...
Конечный результат заключается в том, что буфер stdout заполняется, и рано или поздно вещи перестают записываться в консоль.
В этом и заключается подвох: если я запускаю приложение автономно, а не из скрипта сборки Apache Ant, я не могу воспроизвести проблему. Так что это может быть связано с тем, как Ant перенаправляет вывод процесса, но я не решаюсь представить отчет об ошибке, потому что кажется, что кто-то другой столкнулся бы с этой проблемой раньше ... и потому что я не могу получить то же самое поведение, чтобы воспроизвести в изоляции.
Есть какие-нибудь мысли или советы о том, как мне отследить это дальше?
ОБНОВЛЕНИЕ : Обновление Eclipse с 3.4.2 до Helios (M2) волшебным образом решило проблему. Я также могу продолжать использовать 3.4.2, запустив встроенный сборщик Ant из командной строки вместо пользовательского интерфейса:
java -jar <eclipse directory>\plugins\org.eclipse.equinox.launcher_<version>.jar -application org.eclipse.ant.core.antRunner -buildfile <buildfile>