Loading...

Details

Type: Bug
Resolution: Done
Priority: Major
Fix Version/s: 2.2.0.Final, 2.0.32.Final, 2.1.5.Final
Affects Version/s: 2.0.30.Final, 2.1.3.Final
Component/s: Core
Labels:
None

Git Pull Request:
https://github.com/undertow-io/undertow/pull/922, https://github.com/undertow-io/undertow/pull/961, https://github.com/undertow-io/undertow/pull/962

Description

DefaultAccessLogReceiver may throw "IOException: Stream closed" or NullPointerException due to a concurrency issue between DefaultAccessLogReceiver#run() and DefaultAccessLogReceiver#close().

If DefaultAccessLogReceiver#close() is invoked while another task thread is executing inside the "finally" clause of DefaultAccessLogReceiver#run(), there's a concurrency issue that allows multiple task threads execute run() in parallel.

This can cause the following "java.io.IOException: Stream closed" or NullPointerException inside run() or writeMessage():

ERROR [io.undertow] (default task-1) UT005016: Error writing access log: java.io.IOException: Stream closed
	at java.io.BufferedWriter.ensureOpen(BufferedWriter.java:116)
	at java.io.BufferedWriter.write(BufferedWriter.java:221)
	at java.io.Writer.write(Writer.java:157)
	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.writeMessage(DefaultAccessLogReceiver.java:245)
	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.run(DefaultAccessLogReceiver.java:188)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at java.lang.Thread.run(Thread.java:748)

ERROR [org.jboss.threads.errors] (default task-1) Thread Thread[default task-1,5,main] threw an uncaught exception: java.lang.NullPointerException
	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.writeMessage(DefaultAccessLogReceiver.java:245)
	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.run(DefaultAccessLogReceiver.java:188)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at java.lang.Thread.run(Thread.java:748)

ERROR [io.undertow] (default task-1) UT005016: Error writing access log: java.io.IOException: Stream closed
	at java.io.BufferedWriter.ensureOpen(BufferedWriter.java:116)
	at java.io.BufferedWriter.flushBuffer(BufferedWriter.java:126)
	at java.io.BufferedWriter.flush(BufferedWriter.java:253)
	at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.run(DefaultAccessLogReceiver.java:201)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at java.lang.Thread.run(Thread.java:748)

ERROR [org.jboss.threads.errors] (default task-1) Thread Thread[default task-3,5,main] threw an uncaught exception: java.lang.NullPointerException
        at io.undertow.server.handlers.accesslog.DefaultAccessLogReceiver.run(DefaultAccessLogReceiver.java:201)
        at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
        at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
        at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348)
        at java.lang.Thread.run(Thread.java:748)

This happens because the "state" is reset to 0 (not running) at the beginning of the "finally" clause of DefaultAccessLogReceiver#run(). So, if another thread (MSC service thread in EAP/WildFly) invokes DefaultAccessLogReceiver#close() at the same time, it has a possibility to trigger "logWriteExecutor.execute(this)" to spawn a new thread that executes run(). (In a normal scenario, "logWriteExecutor.execute(this)" needs to be executed here in order to close a writer. So, I think close() itself is fine.)

I think the "state" should be set at the end of the finally clause to prevent other threads from entering DefaultAccessLogReceiver#run().

Attachments

Issue Links

is cloned by

JBEAP-20055 [GSS](7.3.z) UNDERTOW-1763 - DefaultAccessLogReceiver may throw "IOException: Stream closed" or NullPointerException due to a concurrency issue on shutdown.

Verified

DefaultAccessLogReceiver may throw "IOException: Stream closed" or NullPointerException due to a concurrency issue

Details

Description

Attachments

Issue Links

Activity

People

Dates