[FTPSERVER-122] Data races are found in FtpStatisticsImpl

• Type: Bug
• Status: Open
• Priority: Minor
• Resolution: Unresolved
• Component/s: Core

Environment

CentOS 5.
[13:54][qiyao@qiyaows:~]$ uname -a
Linux qiyaows.dyndns.org 2.6.18-8.1.8.el5 #1 SMP Tue Jul 10 06:50:22 EDT 2007 i686 i686 i386 GNU/Linux

[13:55][qiyao@qiyaows:~]$ java -version
java version "1.6.0"
Java(TM) SE Runtime Environment (build pxi3260-20071123_01)
IBM J9 VM (build 2.4, J2RE 1.6.0 IBM J9 2.4 Linux x86-32 jvmxi3260-20071121_15015 (JIT enabled)
J9VM - 20071121_015015_lHdSMR
JIT - r9_20071121_1330
GC - 20071031_AA)
JCL - 20071118_01

• Assignee: Unassigned
• Reporter: Yao Qi
• Created: 10/Apr/08 06:19
• Updated: 10/Apr/08 06:19

Description

We are developing a runtime analysis tool for java program, MTRAT (http://www.alphaworks.ibm.com/tech/mtrat), and we find two data races when we check ftpserver by MTRAT.

currAnonLogins and currLogins are accessed without any protection by locks. This problem also exists for other private fields. Hopefully, AtomicInteger/AtuomicLong in java.util.concurrent.atomic package could be used to fix this bug.

Steps to show this bug,
1. We launch ftpserver command line with the instrumentation and analysis of MTRAT .

[12:41][qiyao@qiyaows:~/SourceCode/svn/ftpserver]$ ~/workspace-3.2/com.ibm.threadanalysis.dynamic/mtrat/mtrat -cp /home/qiyao/SourceCode/svn/ftpserver/./core/target/classes:/home/qiyao/SourceCode/svn/ftpserver/./ftplet-api/target/classes:/home/qiyao/SourceCode/svn/ftpserver/./commons-net-2/target/classes:/home/qiyao/.m2/repository/commons-codec/commons-codec/1.3/commons-codec-1.3.jar:/home/qiyao/.m2/repository/hsqldb/hsqldb/1.8.0.7/hsqldb-1.8.0.7.jar:/home/qiyao/.m2/repository/log4j/log4j/1.2.13/log4j-1.2.13.jar:/home/qiyao/.m2/repository/org/slf4j/slf4j-api/1.4.3/slf4j-api-1.4.3.jar:/home/qiyao/.m2/repository/org/slf4j/slf4j-log4j12/1.4.3/slf4j-log4j12-1.4.3.jar:/home/qiyao/.m2/repository/org/apache/mina/mina-core/2.0.0-M2-SNAPSHOT/mina-core-2.0.0-M2-SNAPSHOT.jar org.apache.ftpserver.commandline.CommandLine -prop ftpd.properties >& log

2. Open two new consoles and login as qiyao and anonymous respectively,
In console 1,
$ ftp
ftp> open localhost 1234
Connected to qiyaows.dyndns.org.
220 Service ready for new user.
KERBEROS_V4 rejected as an authentication type
Name (localhost:qiyao): anonymous
331 Guest login okay, send your complete e-mail address as password.
Password:
230 User logged in, proceed.
Remote system type is UNIX.
ftp> bye
221 Goodbye.

In console 2,
ftp> open localhost 1234
Connected to qiyaows.dyndns.org.
220 Service ready for new user.
KERBEROS_V4 rejected as an authentication type
Name (localhost:qiyao): qiyao
331 User name okay, need password for qiyao.
Password:
230 User logged in, proceed.
Remote system type is UNIX.
ftp> bye

3. Data race report from MTRAT.
Data Race 71 : 680 : org/apache/ftpserver/FtpStatisticsImpl : currAnonLogins
Thread pool-1-thread-1 id: 13 : WRITE
org.apache.ftpserver.FtpStatisticsImpl : setLogin : 303
org.apache.ftpserver.command.PASS : execute : 205
org.apache.ftpserver.DefaultFtpHandler : messageReceived : 79
org.apache.ftpserver.listener.mina.FtpHandlerAdapter : messageReceived : 54
org.apache.mina.common.DefaultIoFilterChain$TailFilter : messageReceived : 743
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
org.apache.mina.common.DefaultIoFilterChain : access$1200 : 40
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1 : messageReceived : 823
org.apache.mina.common.IoFilterEvent : fire : 54
org.apache.mina.filter.logging.MdcInjectionFilter : filter : 137
org.apache.mina.filter.util.CommonEventFilter : messageReceived : 67
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
org.apache.mina.common.DefaultIoFilterChain : access$1200 : 40
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1 : messageReceived : 823
.....
Thread pool-1-thread-4 id: 17 : READ
org.apache.ftpserver.FtpStatisticsImpl : getCurrentAnonymousLoginNumber : 191
org.apache.ftpserver.command.USER : execute : 95
org.apache.ftpserver.DefaultFtpHandler : messageReceived : 79
org.apache.ftpserver.listener.mina.FtpHandlerAdapter : messageReceived : 54
org.apache.mina.common.DefaultIoFilterChain$TailFilter : messageReceived : 743
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
org.apache.mina.common.DefaultIoFilterChain : access$1200 : 40
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1 : messageReceived : 823
org.apache.mina.common.IoFilterEvent : fire : 54
org.apache.mina.filter.logging.MdcInjectionFilter : filter : 137
org.apache.mina.filter.util.CommonEventFilter : messageReceived : 67
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405

Data Race 72 : 680 : org/apache/ftpserver/FtpStatisticsImpl : currLogins
Thread pool-1-thread-1 id: 13 : WRITE
org.apache.ftpserver.FtpStatisticsImpl : setLogin : 299
org.apache.ftpserver.command.PASS : execute : 205
org.apache.ftpserver.DefaultFtpHandler : messageReceived : 79
org.apache.ftpserver.listener.mina.FtpHandlerAdapter : messageReceived : 54
org.apache.mina.common.DefaultIoFilterChain$TailFilter : messageReceived : 743
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
org.apache.mina.common.DefaultIoFilterChain : access$1200 : 40
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1 : messageReceived : 823
org.apache.mina.common.IoFilterEvent : fire : 54
org.apache.mina.filter.logging.MdcInjectionFilter : filter : 137
org.apache.mina.filter.util.CommonEventFilter : messageReceived : 67
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
.....
Thread pool-1-thread-4 id: 17 : READ
org.apache.ftpserver.FtpStatisticsImpl : getCurrentLoginNumber : 177
org.apache.ftpserver.command.USER : execute : 103
org.apache.ftpserver.DefaultFtpHandler : messageReceived : 79
org.apache.ftpserver.listener.mina.FtpHandlerAdapter : messageReceived : 54
org.apache.mina.common.DefaultIoFilterChain$TailFilter : messageReceived : 743
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405
org.apache.mina.common.DefaultIoFilterChain : access$1200 : 40
org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1 : messageReceived : 823
org.apache.mina.common.IoFilterEvent : fire : 54
org.apache.mina.filter.logging.MdcInjectionFilter : filter : 137
org.apache.mina.filter.util.CommonEventFilter : messageReceived : 67
org.apache.mina.common.DefaultIoFilterChain : callNextMessageReceived : 405