У меня есть приложение, которое объединяет все свои журналы в класс с одним экземпляром, чтобы облегчить выборочная отладочная печать и т. д. Класс существует около года и работает без сбоев, но совсем недавно мне довелось установить уровень журнала до максимального значения (что я делаю редко), и стандартный вывод , кажется, в конечном итоге блокирует . Это вызовет хаос в следующий раз, когда какая-то другая часть кода вызовет println
, или когда он пытается использовать класс ведения журнала (который заблокирован в ожидании возврата println
).
Моя первая мысль заключалась в том, что у меня была какая-то проблема с параллелизмом с моим классом ведения журнала, но просматриваю стек traces убеждает меня, что моя синхронизация работает правильно и что только один поток пытается писать на консоль в любой момент времени. Вот пример трассировки стека в потоке-нарушителе:
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 блокирует собственный вызов Windows ZwWriteFile
. Мое лучшее предположение состоит в том, что 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>