Bug 58371 - Data races on field org.apache.tomcat.util.buf.MessageBytes.hasStrValue & strValue
Summary: Data races on field org.apache.tomcat.util.buf.MessageBytes.hasStrValue & str...
Status: RESOLVED FIXED
Alias: None
Product: Tomcat 8
Classification: Unclassified
Component: Util (show other bugs)
Version: 8.0.x-trunk
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ----
Assignee: Tomcat Developers Mailing List
URL:
Keywords:
: 58399 (view as bug list)
Depends on:
Blocks:
 
Reported: 2015-09-12 01:25 UTC by Yilong Li
Modified: 2015-09-18 08:58 UTC (History)
0 users


Attachments
Add an attachment (proposed patch, testcase, etc.)

Note You need to log in before you can comment on or make changes to this bug.
Description Yilong Li 2015-09-12 01:25:15 UTC 
Reported by RV-Predict (a dynamic race detector) when running the test suite:
Data race on field org.apache.tomcat.util.buf.MessageBytes.hasStrValue: {{{
    Concurrent read in thread T18 (locks held: {Monitor@56dc46b6})
 ---->  at org.apache.tomcat.util.buf.MessageBytes.toString(MessageBytes.java:156)
        at org.apache.catalina.connector.Request.getRequestURI(Request.java:2178)
        at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:202)
        - locked Monitor@56dc46b6 at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:192) 
        at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:187)
        at org.apache.catalina.core.TestAsyncContextImpl$DispatchingServlet$1.run(TestAsyncContextImpl.java:710)
    T18 is created by T17
        at org.apache.catalina.core.TestAsyncContextImpl$DispatchingServlet.doGet(TestAsyncContextImpl.java:715)

    Concurrent write in thread T17 (locks held: {Monitor@74cf9f3a})
 ---->  at org.apache.tomcat.util.buf.MessageBytes.toString(MessageBytes.java:167)
        at org.apache.coyote.RequestInfo.updateCounters(RequestInfo.java:167)
        at org.apache.coyote.Request.updateCounters(Request.java:566)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1153)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:673)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:277)
        - locked Monitor@74cf9f3a at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:259) 
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    T17 is created by T15
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1010)
}}}

Consider declaring hasStrValue as volatile to avoid instructions reordering?
Comment 1 Yilong Li 2015-09-12 16:30:10 UTC 
One more report on field strValue:
Data race on field org.apache.tomcat.util.buf.MessageBytes.strValue: {{{
    Concurrent read in thread T20 (locks held: {Monitor@45a7152e})
 ---->  at org.apache.tomcat.util.buf.MessageBytes.toString(MessageBytes.java:157)
        at org.apache.catalina.connector.Request.getRequestURI(Request.java:2178)
        at org.apache.catalina.connector.Request.getContextPath(Request.java:1918)
        at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:203)
        - locked Monitor@45a7152e at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:192)
        at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:187)
        at org.apache.catalina.core.TestAsyncContextImpl$DispatchingServlet$1.run(TestAsyncContextImpl.java:710)
    T20 is created by T19
        at org.apache.catalina.core.TestAsyncContextImpl$DispatchingServlet.doGet(TestAsyncContextImpl.java:715)

    Concurrent write in thread T19 (locks held: {Monitor@75c39be9})
 ---->  at org.apache.tomcat.util.buf.MessageBytes.toString(MessageBytes.java:166)
        at org.apache.coyote.RequestInfo.updateCounters(RequestInfo.java:167)
        at org.apache.coyote.Request.updateCounters(Request.java:566)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1153)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:673)
        at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1074)
        at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.run(Nio2Endpoint.java:1033)
        - locked Monitor@75c39be9 at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.run(Nio2Endpoint.java:1032)
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
    T19 is created by T18
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1010)
}}}
Comment 2 Mark Thomas 2015-09-14 15:43:46 UTC 
root cause is trying to build the request statistics when switching from sync to async rather than waiting until the request processing is complete.

Fixed in trunk and 8.0.x for 8.0.27 onwards.
Comment 3 Mark Thomas 2015-09-18 08:58:57 UTC 
*** Bug 58399 has been marked as a duplicate of this bug. ***