Return-Path: Delivered-To: apmail-tomcat-dev-archive@www.apache.org Received: (qmail 59961 invoked from network); 1 Jul 2008 13:55:42 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (140.211.11.2) by minotaur.apache.org with SMTP; 1 Jul 2008 13:55:42 -0000 Received: (qmail 32694 invoked by uid 500); 1 Jul 2008 13:55:41 -0000 Delivered-To: apmail-tomcat-dev-archive@tomcat.apache.org Received: (qmail 32119 invoked by uid 500); 1 Jul 2008 13:55:39 -0000 Mailing-List: contact dev-help@tomcat.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: "Tomcat Developers List" Delivered-To: mailing list dev@tomcat.apache.org Received: (qmail 32108 invoked by uid 99); 1 Jul 2008 13:55:39 -0000 Received: from athena.apache.org (HELO athena.apache.org) (140.211.11.136) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 01 Jul 2008 06:55:39 -0700 X-ASF-Spam-Status: No, hits=-0.0 required=10.0 tests=SPF_PASS X-Spam-Check-By: apache.org Received-SPF: pass (athena.apache.org: domain of qiyaoltc@gmail.com designates 64.233.178.244 as permitted sender) Received: from [64.233.178.244] (HELO hs-out-0708.google.com) (64.233.178.244) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 01 Jul 2008 13:54:48 +0000 Received: by hs-out-0708.google.com with SMTP id x43so374312hsb.0 for ; Tue, 01 Jul 2008 06:55:08 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=gamma; h=domainkey-signature:received:received:message-id:date:from:to :subject:in-reply-to:mime-version:content-type :content-transfer-encoding:content-disposition:references; bh=6aEhvoiQxMwW5pBwe6z2ZgCCwt2qmzAZtQw+24qt88E=; b=Bi/d1jHVqnzpqdiMynPlVt7sJwXS2W2NGD6Jzw0jPZnQspl3hrhzdIsKuSFpv5wYIU ooawvL1bGTZvE+aIuPQ+OCLP17Mw9OAa2XZLKJX0lNs3CIWjDTqTEM3exLOGlKtN/R79 7ZP4isYJB4tzE/QrwKjC1MqoyVbXQbg3FnZ7k= DomainKey-Signature: a=rsa-sha1; c=nofws; d=gmail.com; s=gamma; h=message-id:date:from:to:subject:in-reply-to:mime-version :content-type:content-transfer-encoding:content-disposition :references; b=m4eGhCbyHo/n6k9GBq2BqEFs+a3fbR9aELde1nkpoABeCoha5CQN4Q2BXrz6kLnDCj v9KwGjucipFdzzpNbX3a0yY2lYv/A9tsiMUxIWA+anV0+MIibCDyS0H+i6ZAqQrXNuIg 4xNaHGicZdHipCExnyK4wITXZja+3g/J8z3yM= Received: by 10.100.250.12 with SMTP id x12mr5794681anh.93.1214920508131; Tue, 01 Jul 2008 06:55:08 -0700 (PDT) Received: by 10.100.58.18 with HTTP; Tue, 1 Jul 2008 06:55:08 -0700 (PDT) Message-ID: Date: Tue, 1 Jul 2008 21:55:08 +0800 From: "Yao Qi" To: dev@tomcat.apache.org Subject: Re: Some potential data races in tomcat In-Reply-To: MIME-Version: 1.0 Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit Content-Disposition: inline References: X-Virus-Checked: Checked by ClamAV on apache.org Could anyone here have a look on these races we found? Any comments are highly appreciated. On 6/18/08, Yao Qi 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