Netty hangs under slow http test

985 views

Skip to first unread message

Minh Chau Hoang

unread,

Nov 23, 2013, 1:04:38 PM11/23/13

to ne...@googlegroups.com

We're trying to load test our Http Netty Server with Slow Http Test (https://code.google.com/p/slowhttptest/) and it turns out that Netty will hang very easily. With the config of 10,000 concurrent slow http connection to the server, it'll start to hang after just about 10s and will not recover. The server is still accept TCP connection, however any Http request will hang with no response.

Any idea how to deal with this situation? My guess is that since the pool of work threads is fully occupied digesting the slow header, new connection is still accepted to the backlog queue via boss thread, however there are none worker thread to process them since they're locked waiting for partial headers.

Norman Maurer

unread,

Nov 23, 2013, 1:27:25 PM11/23/13

to ne...@googlegroups.com, Minh Chau Hoang

Maybe you are blocking the IO-Threads ? You can check with yourkit or visualvm for it.

It’s very hard to say without see your code and know more about the setup (like netty version etc).

--
Norman Maurer

nma...@redhat.com

JBoss, by Red Hat

On 23. November 2013 at 19:25:36, Minh Chau Hoang (kid...@gmail.com) wrote:

We're trying to load test our Http Netty Server with Slow Http Test (https://code.google.com/p/slowhttptest/) and it turns out that Netty will hang very easily. With the config of 10,000 concurrent slow http connection to the server, it'll start to hang after just about 10s and will not recover. The server is still accept TCP connection, however any Http request will hang with no response.

Any idea how to deal with this situation? My guess is that since the pool of work threads is fully occupied digesting the slow header, new connection is still accepted to the backlog queue via boss thread, however there are none worker thread to process them since they're locked waiting for partial headers.

--

---
You received this message because you are subscribed to the Google Groups "Netty discussions" group.
To unsubscribe from this group and stop receiving emails from it, send an email to netty+un...@googlegroups.com.
For more options, visit https://groups.google.com/groups/opt_out.

Minh Chau Hoang

unread,

Nov 23, 2013, 1:41:12 PM11/23/13

to ne...@googlegroups.com, Minh Chau Hoang, nma...@redhat.com

Sorry very much for lack of information.

We're using Netty 3.5.4.

Here is our pipeline:

pipeline.addLast("decoder", new HttpRequestDecoder());

pipeline.addLast("aggregator", new HttpChunkAggregator(65536));

pipeline.addLast("encoder", new HttpResponseEncoder());

pipeline.addLast("handler", new WebSocketServerHandler());

pipeline.addLast("frameDecoder", new DelimiterBasedFrameDecoder(1024 *1024, Delimiters.nulDelimiter()));

Where WebSocketServerHandler is our handler, which includes some put message into a blocking queue (such as writing log, this is my current suspect). However this condition happens only under slow http test. Other kind of load does not make it happen. As a 'fun' test, we did it under windows 7 environment, it doesn't happen neither. (our deplon env is CentOS).

The thread dump when it hangs:

"Thread-0" id=11 idx=0x3c tid=2121 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95e4bdc8

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at PriceBoard/log/LogText.run(LogText.java:101)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-2" id=13 idx=0x40 tid=2122 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95e4be40

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at PriceBoard/log/LogText.run(LogText.java:101)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-3" id=14 idx=0x44 tid=2123 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95e4beb8

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at PriceBoard/log/LogText.run(LogText.java:101)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-4" id=15 idx=0x48 tid=2124 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95f2a860

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at websocket/data/DataQueue.get(DataQueue.java:32)

at PriceBoard/data/handlers/DataHandlerBase.getMsgAndProcess(DataHandlerBase.java:39)

at PriceBoard/data/handlers/PersistentDataHandler.run(PersistentDataHandler.java:22)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-5" id=16 idx=0x4c tid=2125 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95f733a0

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at websocket/data/DataQueue.get(DataQueue.java:32)

at PriceBoard/data/handlers/DataHandlerBase.getMsgAndProcess(DataHandlerBase.java:39)

at PriceBoard/data/handlers/BroadcastDataHandler.run(BroadcastDataHandler.java:26)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-6" id=17 idx=0x50 tid=2126 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95f2aa30

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at websocket/data/DataQueue.get(DataQueue.java:32)

at PriceBoard/data/handlers/DataHandlerBase.getMsgAndProcess(DataHandlerBase.java:39)

at PriceBoard/data/handlers/InMemDataHandler.run(InMemDataHandler.java:25)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-7" id=18 idx=0x54 tid=2127 prio=5 alive, in native

at jrockit/net/SocketNativeIO.readBytesPinned(Ljava/io/FileDescriptor;[BIII)I(Native Method)

at jrockit/net/SocketNativeIO.socketRead(SocketNativeIO.java:32)

at java/net/SocketInputStream.socketRead0(Ljava/io/FileDescriptor;[BIII)I(SocketInputStream.java)

at java/net/SocketInputStream.read(SocketInputStream.java:129)

at PriceBoard/data/handlers/MainDataHandler.read(MainDataHandler.java:1707)

at PriceBoard/data/handlers/MainDataHandler.recvBytes(MainDataHandler.java:1726)

at PriceBoard/data/handlers/MainDataHandler.receiveMessage(MainDataHandler.java:1697)

at PriceBoard/data/handlers/MainDataHandler.run(MainDataHandler.java:613)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-8" id=19 idx=0x58 tid=2128 prio=5 alive, sleeping, native_waiting

at java/lang/Thread.sleep(J)V(Native Method)

at PriceBoard/data/handlers/ImageCreator.run(ImageCreator.java:64)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"Thread-9" id=20 idx=0x5c tid=2129 prio=5 alive, parked, native_blocked

-- Parking to wait for: java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject@0x95f2b068

at jrockit/vm/Locks.park0(J)V(Native Method)

at jrockit/vm/Locks.park(Locks.java:2230)

at sun/misc/Unsafe.park(ZJ)V(Native Method)

at java/util/concurrent/locks/LockSupport.park(LockSupport.java:156)

at java/util/concurrent/locks/AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java/util/concurrent/LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)

at PriceBoard/log/LogText.run(LogText.java:101)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"New I/O worker #1" id=22 idx=0x60 tid=2130 prio=5 alive, in native

at sun/nio/ch/EPollArrayWrapper.epollWait(JIJI)I(Native Method)

at sun/nio/ch/EPollArrayWrapper.poll(EPollArrayWrapper.java:210)

at sun/nio/ch/EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)

at sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)

^-- Holding lock: sun/nio/ch/Util$2@0x95f6a098[biased lock]

^-- Holding lock: java/util/Collections$UnmodifiableSet@0x95f6a088[biased lock]

^-- Holding lock: sun/nio/ch/EPollSelectorImpl@0x95f69ff0[biased lock]

at sun/nio/ch/SelectorImpl.select(SelectorImpl.java:80)

at org/jboss/netty/channel/socket/nio/SelectorUtil.select(SelectorUtil.java:64)

at org/jboss/netty/channel/socket/nio/AbstractNioSelector.select(AbstractNioSelector.java:409)

at org/jboss/netty/channel/socket/nio/AbstractNioSelector.run(AbstractNioSelector.java:206)

at org/jboss/netty/channel/socket/nio/AbstractNioWorker.run(AbstractNioWorker.java:88)

at org/jboss/netty/channel/socket/nio/NioWorker.run(NioWorker.java:178)

at org/jboss/netty/util/ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)

at org/jboss/netty/util/internal/DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)

at java/util/concurrent/ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

at java/util/concurrent/ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)

at java/lang/Thread.run(Thread.java:662)

at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

-- end of trace

"New I/O worker #2" id=23 idx=0x64 tid=2131 prio=5 alive, in native

at sun/nio/ch/EPollArrayWrapper.epollWait(JIJI)I(Native Method)

at sun/nio/ch/EPollArrayWrapper.poll(EPollArrayWrapper.java:210)

at sun/nio/ch/EPollSelectorImpl.doSelect(EPollSelectorImpl.java:65)

at sun/nio/ch/SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)

^-- Holding lock: sun/nio/ch/Util$2@0x95f73b80[biased lock]

^-- Holding lock: java/util/Collections$UnmodifiableSet@0x95f73b70[biased lock]

^-- Holding lock: sun/nio/ch/EPollSelectorImpl@0x95f73ae0[biased lock]