[DIRMINA-651] Data Race in org.apache.mina.core.session.AbstractIoSession

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.0.0-M4
• Fix Version/s: 2.0.0-RC1
• Component/s: Core

Environment

[daniel@daniel-desk ~]$ uname -a
Linux daniel-desk.dyndns.org 2.6.18-92.el5 #1 SMP Tue Apr 29 13:16:12 EDT 2008 i686 i686 i386 GNU/Linux
[daniel@daniel-desk ~]$ java -version
java version "1.6.0"
Java(TM) SE Runtime Environment (build pxi3260sr2-20080818_01(SR2))
IBM J9 VM (build 2.4, J2RE 1.6.0 IBM J9 2.4 Linux x86-32 jvmxi3260-20080816_22093 (JIT enabled, AOT enabled)
J9VM - 20080816_022093_lHdSMr
JIT - r9_20080721_1330ifx2
GC - 20080724_AA)
JCL - 20080808_02

• Assignee: Julien Vermillard
• Reporter: Daniel Luo
• Created: 19/Dec/08 12:33
• Updated: 19/Oct/09 20:15
• Resolved: 24/Aug/09 14:56

Description

We run ftpserver-1.0.0-M4 with our tool (http://www.alphaworks.ibm.com/tech/mtrat) and one user logins to the server, then a data race is reported. The data race happens in the field "readMessages" of class "org/apache/mina/transport/socket/nio/NioSocketSession". Thread "pool-3-thread-1" read this field while thread "pool-2-thread-1" write to it, which both threads don't share the same lock to protect the critical section.

Data Race 4 : 1526 : org/apache/mina/transport/socket/nio/NioSocketSession : readMessages
Thread "pool-3-thread-1" : Tid 15 : Rid 1540 : READ
Lock Set : [ ]
Vector Clock : 3
[org/apache/mina/core/session/AbstractIoSession : updateThroughput : 667]
[org/apache/mina/core/session/IdleStatusChecker : updateThroughput : 265]
[org/apache/mina/core/session/IdleStatusChecker : notifyIdleSession : 201]
[org/apache/mina/core/session/IdleStatusChecker : notifyIdleness : 150]
[org/apache/mina/core/polling/AbstractPollingIoProcessor : notifyIdleSessions : 604]
[org/apache/mina/core/polling/AbstractPollingIoProcessor : access$700 : 58]
[org/apache/mina/core/polling/AbstractPollingIoProcessor$Worker : run : 863]
[org/apache/mina/util/NamePreservingRunnable : run : 51]
Thread "pool-2-thread-1" : Tid 16 : Rid 1683 : WRITE
Lock Set : [ ]
Vector Clock : 2
[org/apache/mina/core/session/AbstractIoSession : increaseReadMessages : 728]
[org/apache/mina/core/filterchain/DefaultIoFilterChain$TailFilter : messageReceived : 746]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : callNextMessageReceived : 414]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : access$1200 : 49]
[org/apache/mina/core/filterchain/DefaultIoFilterChain$EntryImpl$1 : messageReceived : 832]
[org/apache/ftpserver/listener/nio/FtpLoggingFilter : messageReceived : 83]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : callNextMessageReceived : 414]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : access$1200 : 49]
[org/apache/mina/core/filterchain/DefaultIoFilterChain$EntryImpl$1 : messageReceived : 832]
[org/apache/mina/core/filterchain/IoFilterEvent : fire : 60]
[org/apache/mina/filter/logging/MdcInjectionFilter : filter : 137]
[org/apache/mina/filter/util/CommonEventFilter : messageReceived : 70]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : callNextMessageReceived : 414]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : access$1200 : 49]
[org/apache/mina/core/filterchain/DefaultIoFilterChain$EntryImpl$1 : messageReceived : 832]
[org/apache/mina/filter/codec/ProtocolCodecFilter$ProtocolDecoderOutputImpl : flush : 379]
[org/apache/mina/filter/codec/ProtocolCodecFilter : messageReceived : 173]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : callNextMessageReceived : 414]
[org/apache/mina/core/filterchain/DefaultIoFilterChain : access$1200 : 49]
[org/apache/mina/core/filterchain/DefaultIoFilterChain$EntryImpl$1 : messageReceived : 832]
[org/apache/mina/core/filterchain/IoFilterEvent : fire : 60]
[org/apache/mina/core/session/IoEvent : run : 64]
[org/apache/mina/filter/executor/OrderedThreadPoolExecutor$Worker : runTask : 551]
[org/apache/mina/filter/executor/OrderedThreadPoolExecutor$Worker : runTasks : 543]
[org/apache/mina/filter/executor/OrderedThreadPoolExecutor$Worker : run : 487]