You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mina.apache.org by Niklas Gustavsson <ni...@protocol7.com> on 2008/03/09 23:00:44 UTC

Threading problem in MdcInjectionFilter

Hi

When doing some load testing on FtpServer, I ran into a threading
issue in MdcInjectionFilter. When adding some load, I frequently get a
ConcurrentModificationException on removing the MDC properties. Here's
the stacktrace:

java.util.ConcurrentModificationException
	at java.util.HashMap$HashIterator.nextEntry(HashMap.java:793)
	at java.util.HashMap$KeyIterator.next(HashMap.java:828)
	at org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter.java:140)
	at org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFilter.java:67)
	at org.apache.mina.common.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:401)
	at org.apache.mina.common.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:38)
	at org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:820)
	at org.apache.mina.common.DefaultIoFilterChain$HeadFilter.messageReceived(DefaultIoFilterChain.java:604)
	at org.apache.mina.common.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:401)
	at org.apache.mina.common.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:395)
	at org.apache.mina.common.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:425)
	at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:387)
	at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:379)
	at org.apache.mina.common.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:43)
	at org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:676)
	at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
	at java.lang.Thread.run(Thread.java:619)

The cause of the problem is a call to setProperty() from
org.apache.ftpserver.command.USER. I'm not familiar enough with the
MDC filter to identify the culprit. Simply synchronizing the context
Map does not help. The test I'm running is quite simple:

package org.apache.ftpserver.clienttests;


public class MdcThreadingTest extends ClientTestTemplate {
	
	public void testLoginMulti() throws Exception {
		tearDown();
		for(int i = 0; i<10000; i++) {
			setUp();
			assertTrue(client.login(ADMIN_USERNAME, ADMIN_PASSWORD));
			tearDown();
		}
		System.out.println("All done!");
	}	
}

Any help would be appreciated!

/niklas

Re: Threading problem in MdcInjectionFilter

Posted by Niklas Gustavsson <ni...@protocol7.com>.
Thanks Maarten!

/niklas

On Mon, Mar 10, 2008 at 9:40 AM, Maarten Bosteels
<mb...@gmail.com> wrote:
> mina 2.0 depends heavily on java 5
>  I am working on the fix.
>
>  Maarten
>
>
>  On Mon, Mar 10, 2008 at 9:24 AM, Niklas Gustavsson <ni...@protocol7.com>
>  wrote:
>
>
>
>  > On Mon, Mar 10, 2008 at 9:03 AM, Emmanuel Lecharny <el...@gmail.com>
>  > wrote:
>  > >  Just check that this change is compatible with the JVM version we are
>  > using.
>  > >
>  > >  I don't remember if MINA should still be compatible with 1.4, and if
>  > >  ConcurrentHashMap is avaialable in 1.4...
>  >
>  > ConcurrentHashMap came with the concurrency classes in 1.5. Since the
>  > bug manifests itself inside of a enhanced for loop I think we should
>  > be fine :-)
>  >
>  > /niklas
>  >
>

Re: Threading problem in MdcInjectionFilter

Posted by Maarten Bosteels <mb...@gmail.com>.
mina 2.0 depends heavily on java 5
I am working on the fix.

Maarten


On Mon, Mar 10, 2008 at 9:24 AM, Niklas Gustavsson <ni...@protocol7.com>
wrote:

> On Mon, Mar 10, 2008 at 9:03 AM, Emmanuel Lecharny <el...@gmail.com>
> wrote:
> >  Just check that this change is compatible with the JVM version we are
> using.
> >
> >  I don't remember if MINA should still be compatible with 1.4, and if
> >  ConcurrentHashMap is avaialable in 1.4...
>
> ConcurrentHashMap came with the concurrency classes in 1.5. Since the
> bug manifests itself inside of a enhanced for loop I think we should
> be fine :-)
>
> /niklas
>

Re: Threading problem in MdcInjectionFilter

Posted by Niklas Gustavsson <ni...@protocol7.com>.
On Mon, Mar 10, 2008 at 9:03 AM, Emmanuel Lecharny <el...@gmail.com> wrote:
>  Just check that this change is compatible with the JVM version we are using.
>
>  I don't remember if MINA should still be compatible with 1.4, and if
>  ConcurrentHashMap is avaialable in 1.4...

ConcurrentHashMap came with the concurrency classes in 1.5. Since the
bug manifests itself inside of a enhanced for loop I think we should
be fine :-)

/niklas

Re: Threading problem in MdcInjectionFilter

Posted by Emmanuel Lecharny <el...@gmail.com>.
Niklas Gustavsson wrote:
> On Sun, Mar 9, 2008 at 11:38 PM, Emmanuel Lecharny <el...@gmail.com> wrote:
>   
>> Niklas Gustavsson wrote:
>>  > When doing some load testing on FtpServer, I ran into a threading
>>  > issue in MdcInjectionFilter.
>>  This error might be something different than a threading issue. This is
>>  a typical error you get when doing a loop on a HashMap, and inside the
>>  loop, you remove the current element and expect the loop to continue.
>>
>>  Switching to another kind of structure should fix this problem, without
>>  changing a lot of code.
>>     
>
> Yes, the MdcInjectionFilter iterates over a Map containing the current
> context, at the same time, setProperty() adds an entry to the same
> Map.. Changing the currently used HashMap into a ConcurrentHashMap
> fixes the issue for me. Now, ConcurrentHashMap does not allow null
> keys or values, but from what I can see, we do not allow null keys and
> treats null values as a removal, so that should be fine. Did I miss
> anything or would you like me to make that change?
>   
Just check that this change is compatible with the JVM version we are using.

I don't remember if MINA should still be compatible with 1.4, and if 
ConcurrentHashMap is avaialable in 1.4...
> /niklas
>
>   


-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org



Re: Threading problem in MdcInjectionFilter

Posted by Niklas Gustavsson <ni...@protocol7.com>.
On Sun, Mar 9, 2008 at 11:38 PM, Emmanuel Lecharny <el...@gmail.com> wrote:
> Niklas Gustavsson wrote:
>  > When doing some load testing on FtpServer, I ran into a threading
>  > issue in MdcInjectionFilter.
>  This error might be something different than a threading issue. This is
>  a typical error you get when doing a loop on a HashMap, and inside the
>  loop, you remove the current element and expect the loop to continue.
>
>  Switching to another kind of structure should fix this problem, without
>  changing a lot of code.

Yes, the MdcInjectionFilter iterates over a Map containing the current
context, at the same time, setProperty() adds an entry to the same
Map.. Changing the currently used HashMap into a ConcurrentHashMap
fixes the issue for me. Now, ConcurrentHashMap does not allow null
keys or values, but from what I can see, we do not allow null keys and
treats null values as a removal, so that should be fine. Did I miss
anything or would you like me to make that change?

/niklas

Re: Threading problem in MdcInjectionFilter

Posted by Emmanuel Lecharny <el...@gmail.com>.
Niklas Gustavsson wrote:
> Hi
>
> When doing some load testing on FtpServer, I ran into a threading
> issue in MdcInjectionFilter. 
This error might be something different than a threading issue. This is 
a typical error you get when doing a loop on a HashMap, and inside the 
loop, you remove the current element and expect the loop to continue.

Switching to another kind of structure should fix this problem, without 
changing a lot of code.

-- 
--
cordialement, regards,
Emmanuel Lécharny
www.iktek.com
directory.apache.org



Re: Threading problem in MdcInjectionFilter

Posted by "이희승 (Trustin Lee)" <tr...@gmail.com>.
It looks like a bug in MdcInjectionFilter.

2008-03-09 (일), 23:00 +0100, Niklas Gustavsson 쓰시길:
> Hi
> 
> When doing some load testing on FtpServer, I ran into a threading
> issue in MdcInjectionFilter. When adding some load, I frequently get a
> ConcurrentModificationException on removing the MDC properties. Here's
> the stacktrace:
> 
> java.util.ConcurrentModificationException
> 	at java.util.HashMap$HashIterator.nextEntry(HashMap.java:793)
> 	at java.util.HashMap$KeyIterator.next(HashMap.java:828)
> 	at org.apache.mina.filter.logging.MdcInjectionFilter.filter(MdcInjectionFilter.java:140)
> 	at org.apache.mina.filter.util.CommonEventFilter.messageReceived(CommonEventFilter.java:67)
> 	at org.apache.mina.common.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:401)
> 	at org.apache.mina.common.DefaultIoFilterChain.access$1200(DefaultIoFilterChain.java:38)
> 	at org.apache.mina.common.DefaultIoFilterChain$EntryImpl$1.messageReceived(DefaultIoFilterChain.java:820)
> 	at org.apache.mina.common.DefaultIoFilterChain$HeadFilter.messageReceived(DefaultIoFilterChain.java:604)
> 	at org.apache.mina.common.DefaultIoFilterChain.callNextMessageReceived(DefaultIoFilterChain.java:401)
> 	at org.apache.mina.common.DefaultIoFilterChain.fireMessageReceived(DefaultIoFilterChain.java:395)
> 	at org.apache.mina.common.AbstractPollingIoProcessor.read(AbstractPollingIoProcessor.java:425)
> 	at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:387)
> 	at org.apache.mina.common.AbstractPollingIoProcessor.process(AbstractPollingIoProcessor.java:379)
> 	at org.apache.mina.common.AbstractPollingIoProcessor.access$400(AbstractPollingIoProcessor.java:43)
> 	at org.apache.mina.common.AbstractPollingIoProcessor$Worker.run(AbstractPollingIoProcessor.java:676)
> 	at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:51)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
> 	at java.lang.Thread.run(Thread.java:619)
> 
> The cause of the problem is a call to setProperty() from
> org.apache.ftpserver.command.USER. I'm not familiar enough with the
> MDC filter to identify the culprit. Simply synchronizing the context
> Map does not help. The test I'm running is quite simple:
> 
> package org.apache.ftpserver.clienttests;
> 
> 
> public class MdcThreadingTest extends ClientTestTemplate {
> 	
> 	public void testLoginMulti() throws Exception {
> 		tearDown();
> 		for(int i = 0; i<10000; i++) {
> 			setUp();
> 			assertTrue(client.login(ADMIN_USERNAME, ADMIN_PASSWORD));
> 			tearDown();
> 		}
> 		System.out.println("All done!");
> 	}	
> }
> 
> Any help would be appreciated!
> 
> /niklas
-- 
Trustin Lee - Principal Software Engineer, JBoss, Red Hat
--
what we call human nature is actually human habit
--
http://gleamynode.net/