You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@tomcat.apache.org by Yao Qi <qi...@gmail.com> on 2008/06/18 07:25:58 UTC
Some potential data races in tomcat
We have been working on a tool (MTRAT, Multi-Thread Runtime Analysis
Tool) for finding potential data races and deadlocks in java programs
and I tried it out on Tomcat 6.0.13. I found some that look like
problems; you might be interested in fixing them, and I would like to
know if my results are correct or not.
1. accessCount in class org.apache.naming.resources.ResourceCache
** Two threads' backtrace to show how race happens,
Thread http-8081-1 id: 23 : WRITE
[org.apache.naming.resources.ResourceCache : lookup : 294]
[org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
[org.apache.naming.resources.ProxyDirContext : lookup : 283]
[org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 736]
[org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
[org.apache.tomcat.util.http.mapper.Mapper : map : 516]
[org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
[org.apache.catalina.connector.CoyoteAdapter : service : 259]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
Thread http-8081-3 id: 25 : WRITE
[org.apache.naming.resources.ResourceCache : lookup : 294]
[org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
[org.apache.naming.resources.ProxyDirContext : lookup : 283]
[org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 782]
[org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
[org.apache.tomcat.util.http.mapper.Mapper : map : 516]
[org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
** Initial analysis: Since two threads invoke
org.apache.naming.resources.ResourceCache::lookup(), in which
accessCount is incremented, there should be a lock to prevent
concurrent increment to accessCount.
2. countAllocated in org.apache.catalina.core.StandardWrapper
** Two threads' backtrace to show how race happens,
Thread http-8081-1 id: 23 : READ
[org.apache.catalina.core.StandardWrapper : allocate : 820]
[org.apache.catalina.core.StandardWrapperValve : invoke : 129]
[org.apache.catalina.core.StandardContextValve : invoke : 175]
[org.apache.catalina.core.StandardHostValve : invoke : 128]
[org.apache.catalina.valves.ErrorReportValve : invoke : 104]
[org.apache.catalina.core.StandardEngineValve : invoke : 109]
[org.apache.catalina.connector.CoyoteAdapter : service : 261]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
Thread http-8081-4 id: 26 : WRITE
[org.apache.catalina.core.StandardWrapper : deallocate : 871]
[org.apache.catalina.core.StandardWrapperValve : invoke : 298]
[org.apache.catalina.core.StandardContextValve : invoke : 175]
[org.apache.catalina.core.StandardHostValve : invoke : 128]
[org.apache.catalina.valves.ErrorReportValve : invoke : 104]
[org.apache.catalina.core.StandardEngineValve : invoke : 109]
[org.apache.catalina.connector.CoyoteAdapter : service : 261]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
** Initial analysis: increment and decrement are performed in
allocate() and deallocate respectively. Since increment and decrement
are *not* atomic, they may involve problems.
3. hitsCount of class org.apache.naming.resources.ResourceCache,
** Two threads' stack backtrace,
Thread http-8081-1 id: 23 : WRITE
Lock Set : [ ]
[org.apache.naming.resources.ResourceCache : lookup : 307]
[org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
[org.apache.naming.resources.ProxyDirContext : lookupCache : 1377]
[org.apache.catalina.servlets.DefaultServlet : serveResource : 643]
[org.apache.catalina.servlets.DefaultServlet : doGet : 325]
[javax.servlet.http.HttpServlet : service : 690]
[javax.servlet.http.HttpServlet : service : 803]
[org.apache.catalina.core.ApplicationFilterChain : internalDoFilter : 290]
[org.apache.catalina.core.ApplicationFilterChain : doFilter : 206]
[org.apache.catalina.core.StandardWrapperValve : invoke : 230]
[org.apache.catalina.core.StandardContextValve : invoke : 175]
[org.apache.catalina.core.StandardHostValve : invoke : 128]
[org.apache.catalina.valves.ErrorReportValve : invoke : 104]
[org.apache.catalina.core.StandardEngineValve : invoke : 109]
[org.apache.catalina.connector.CoyoteAdapter : service : 261]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
Thread http-8081-2 id: 24 : READ
Lock Set : [ 705(org/apache/naming/resources/ResourceCache), ]
[org.apache.naming.resources.ResourceCache : lookup : 307]
[org.apache.naming.resources.ProxyDirContext : cacheLoad : 1600]
[org.apache.naming.resources.ProxyDirContext : cacheLookup : 1449]
[org.apache.naming.resources.ProxyDirContext : lookup : 283]
[org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 782]
[org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
[org.apache.tomcat.util.http.mapper.Mapper : map : 516]
[org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
[org.apache.catalina.connector.CoyoteAdapter : service : 259]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
** Initial analysis: Thread http-8081-2 id acquired a lock in
org.apache.naming.resources.ProxyDirContext::cacheLoad (line 1598 ~
line 1603), but
Thread http-8081-1 does hold any lock to access hitCount of class
ResouceCache.
4. currentDate of class org.apache.tomcat.util.http.FastHttpDateFormat,
** Two threads' stack backtrace,
Thread http-8081-2 id: 24 : WRITE
Lock Set : [ 878(UnknownClass), ]
[org.apache.tomcat.util.http.FastHttpDateFormat : getCurrentDate : 116]
[org.apache.coyote.http11.Http11Processor : prepareResponse : 1566]
[org.apache.coyote.http11.Http11Processor : action : 934]
[org.apache.coyote.Response : action : 183]
[org.apache.coyote.Response : sendHeaders : 379]
[org.apache.catalina.connector.OutputBuffer : doFlush : 305]
[org.apache.catalina.connector.OutputBuffer : close : 273]
[org.apache.catalina.connector.Response : finishResponse : 486]
[org.apache.catalina.connector.CoyoteAdapter : service : 285]
[org.apache.coyote.http11.Http11Processor : process : 844]
[org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
: process : 581]
[org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
[java.lang.Thread : run : 735]
Thread http-8081-1 id: 23 : READ
Lock Set : [ ]
[org.apache.tomcat.util.http.FastHttpDateFormat : getCurrentDate : 120]
[org.apache.coyote.http11.Http11Processor : prepareResponse : 1566]
[org.apache.coyote.http11.Http11Processor : action : 934]
[org.apache.coyote.Response : action : 183]
[org.apache.coyote.Response : sendHeaders : 379]
[org.apache.catalina.connector.OutputBuffer : doFlush : 305]
[org.apache.catalina.connector.OutputBuffer : close : 273]
[org.apache.catalina.connector.Response : finishResponse : 486]
[org.apache.catalina.connector.CoyoteAdapter : service : 285]
[org.apache.coyote.http11.Http11Processor : process : 844]
** Initial analysis: Write operation (line 116)to currentDate is in
synchronized block, while read operation (line 120) is *not* in
synchronization block. According to our definition to data race,
which is two threads access the memory without order constraint and at
least one is write, we believe that this is a data race. If that read
operation could be placed within synchronization block, this race
could go away.
I'd love to get your feedback on whether our races and my
understanding of this code are correct or not.
--
Yao Qi
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org
Re: Some potential data races in tomcat
Posted by Yao Qi <qi...@gmail.com>.
Could anyone here have a look on these races we found? Any comments
are highly appreciated.
On 6/18/08, Yao Qi <qi...@gmail.com> wrote:
> We have been working on a tool (MTRAT, Multi-Thread Runtime Analysis
> Tool) for finding potential data races and deadlocks in java programs
> and I tried it out on Tomcat 6.0.13. I found some that look like
> problems; you might be interested in fixing them, and I would like to
> know if my results are correct or not.
>
> 1. accessCount in class org.apache.naming.resources.ResourceCache
> ** Two threads' backtrace to show how race happens,
> Thread http-8081-1 id: 23 : WRITE
>
> [org.apache.naming.resources.ResourceCache : lookup : 294]
> [org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
> [org.apache.naming.resources.ProxyDirContext : lookup : 283]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 736]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
> [org.apache.tomcat.util.http.mapper.Mapper : map : 516]
> [org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
> [org.apache.catalina.connector.CoyoteAdapter : service : 259]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
>
> Thread http-8081-3 id: 25 : WRITE
>
> [org.apache.naming.resources.ResourceCache : lookup : 294]
> [org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
> [org.apache.naming.resources.ProxyDirContext : lookup : 283]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 782]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
> [org.apache.tomcat.util.http.mapper.Mapper : map : 516]
> [org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
>
> ** Initial analysis: Since two threads invoke
> org.apache.naming.resources.ResourceCache::lookup(), in which
> accessCount is incremented, there should be a lock to prevent
> concurrent increment to accessCount.
>
> 2. countAllocated in org.apache.catalina.core.StandardWrapper
> ** Two threads' backtrace to show how race happens,
>
> Thread http-8081-1 id: 23 : READ
> [org.apache.catalina.core.StandardWrapper : allocate : 820]
> [org.apache.catalina.core.StandardWrapperValve : invoke : 129]
> [org.apache.catalina.core.StandardContextValve : invoke : 175]
> [org.apache.catalina.core.StandardHostValve : invoke : 128]
> [org.apache.catalina.valves.ErrorReportValve : invoke : 104]
> [org.apache.catalina.core.StandardEngineValve : invoke : 109]
> [org.apache.catalina.connector.CoyoteAdapter : service : 261]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
>
> Thread http-8081-4 id: 26 : WRITE
>
> [org.apache.catalina.core.StandardWrapper : deallocate : 871]
> [org.apache.catalina.core.StandardWrapperValve : invoke : 298]
> [org.apache.catalina.core.StandardContextValve : invoke : 175]
> [org.apache.catalina.core.StandardHostValve : invoke : 128]
> [org.apache.catalina.valves.ErrorReportValve : invoke : 104]
> [org.apache.catalina.core.StandardEngineValve : invoke : 109]
> [org.apache.catalina.connector.CoyoteAdapter : service : 261]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
>
> ** Initial analysis: increment and decrement are performed in
> allocate() and deallocate respectively. Since increment and decrement
> are *not* atomic, they may involve problems.
>
> 3. hitsCount of class org.apache.naming.resources.ResourceCache,
>
> ** Two threads' stack backtrace,
> Thread http-8081-1 id: 23 : WRITE
> Lock Set : [ ]
> [org.apache.naming.resources.ResourceCache : lookup : 307]
> [org.apache.naming.resources.ProxyDirContext : cacheLookup : 1444]
> [org.apache.naming.resources.ProxyDirContext : lookupCache : 1377]
> [org.apache.catalina.servlets.DefaultServlet : serveResource : 643]
> [org.apache.catalina.servlets.DefaultServlet : doGet : 325]
> [javax.servlet.http.HttpServlet : service : 690]
> [javax.servlet.http.HttpServlet : service : 803]
> [org.apache.catalina.core.ApplicationFilterChain : internalDoFilter :
> 290]
> [org.apache.catalina.core.ApplicationFilterChain : doFilter : 206]
> [org.apache.catalina.core.StandardWrapperValve : invoke : 230]
> [org.apache.catalina.core.StandardContextValve : invoke : 175]
> [org.apache.catalina.core.StandardHostValve : invoke : 128]
> [org.apache.catalina.valves.ErrorReportValve : invoke : 104]
> [org.apache.catalina.core.StandardEngineValve : invoke : 109]
> [org.apache.catalina.connector.CoyoteAdapter : service : 261]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
> Thread http-8081-2 id: 24 : READ
> Lock Set : [ 705(org/apache/naming/resources/ResourceCache), ]
>
> [org.apache.naming.resources.ResourceCache : lookup : 307]
> [org.apache.naming.resources.ProxyDirContext : cacheLoad : 1600]
> [org.apache.naming.resources.ProxyDirContext : cacheLookup : 1449]
> [org.apache.naming.resources.ProxyDirContext : lookup : 283]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMapWrapper : 782]
> [org.apache.tomcat.util.http.mapper.Mapper : internalMap : 626]
> [org.apache.tomcat.util.http.mapper.Mapper : map : 516]
> [org.apache.catalina.connector.CoyoteAdapter : postParseRequest : 419]
> [org.apache.catalina.connector.CoyoteAdapter : service : 259]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
>
> ** Initial analysis: Thread http-8081-2 id acquired a lock in
> org.apache.naming.resources.ProxyDirContext::cacheLoad (line 1598 ~
> line 1603), but
> Thread http-8081-1 does hold any lock to access hitCount of class
> ResouceCache.
>
> 4. currentDate of class org.apache.tomcat.util.http.FastHttpDateFormat,
> ** Two threads' stack backtrace,
>
> Thread http-8081-2 id: 24 : WRITE
> Lock Set : [ 878(UnknownClass), ]
>
> [org.apache.tomcat.util.http.FastHttpDateFormat : getCurrentDate :
> 116]
> [org.apache.coyote.http11.Http11Processor : prepareResponse : 1566]
> [org.apache.coyote.http11.Http11Processor : action : 934]
> [org.apache.coyote.Response : action : 183]
> [org.apache.coyote.Response : sendHeaders : 379]
> [org.apache.catalina.connector.OutputBuffer : doFlush : 305]
> [org.apache.catalina.connector.OutputBuffer : close : 273]
> [org.apache.catalina.connector.Response : finishResponse : 486]
> [org.apache.catalina.connector.CoyoteAdapter : service : 285]
> [org.apache.coyote.http11.Http11Processor : process : 844]
> [org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler
> : process : 581]
> [org.apache.tomcat.util.net.JIoEndpoint$Worker : run : 447]
> [java.lang.Thread : run : 735]
> Thread http-8081-1 id: 23 : READ
> Lock Set : [ ]
>
> [org.apache.tomcat.util.http.FastHttpDateFormat : getCurrentDate :
> 120]
> [org.apache.coyote.http11.Http11Processor : prepareResponse : 1566]
> [org.apache.coyote.http11.Http11Processor : action : 934]
> [org.apache.coyote.Response : action : 183]
> [org.apache.coyote.Response : sendHeaders : 379]
> [org.apache.catalina.connector.OutputBuffer : doFlush : 305]
> [org.apache.catalina.connector.OutputBuffer : close : 273]
> [org.apache.catalina.connector.Response : finishResponse : 486]
> [org.apache.catalina.connector.CoyoteAdapter : service : 285]
> [org.apache.coyote.http11.Http11Processor : process : 844]
>
> ** Initial analysis: Write operation (line 116)to currentDate is in
> synchronized block, while read operation (line 120) is *not* in
> synchronization block. According to our definition to data race,
> which is two threads access the memory without order constraint and at
> least one is write, we believe that this is a data race. If that read
> operation could be placed within synchronization block, this race
> could go away.
>
> I'd love to get your feedback on whether our races and my
> understanding of this code are correct or not.
>
> --
> Yao Qi
>
--
Yao
GNU/Linux Developer
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@tomcat.apache.org
For additional commands, e-mail: dev-help@tomcat.apache.org