I am writing an embedded application using using Jetty 9.3.4.v20151007
(server+servlet) and slf4j 1.7.12 under Java 8 (1.8.0_60)
I had been running under Jetty 9.3.1.v20150714 when this issue was first
observed; the upgrade had no effect.
The application generally runs well and appears to be stable, responding
well to curl and various browsers, but I have a high frequency problem
which is only observed when load-testing my application with apache 'ab'
When using the following command line
$ ab -n 1000 -c 8 -p data2.json -T application/json
localhost:7718/init-test2
every request completes properly with a 200 but my logs are filled up
with stack traces like that listed below, approximately 1 per 100 requests
which, to me, suggests a race condition.
SLF4J: Failed toString() invocation on an object of type
[org.eclipse.jetty.server.HttpConnection]
java.lang.IndexOutOfBoundsException
at java.nio.Buffer.checkIndex(Buffer.java:540)
at java.nio.HeapByteBuffer.get(HeapByteBuffer.java:139)
at org.eclipse.jetty.util.BufferUtil.appendDebugString(BufferUtil.java:1042)
at org.eclipse.jetty.util.BufferUtil.toDetailString(BufferUtil.java:1021)
at org.eclipse.jetty.server.HttpConnection.toString(HttpConnection.java:563)
at
org.slf4j.helpers.MessageFormatter.safeObjectAppend(MessageFormatter.java:297)
at
org.slf4j.helpers.MessageFormatter.deeplyAppendParameter(MessageFormatter.java:269)
at org.slf4j.helpers.MessageFormatter.arrayFormat(MessageFormatter.java:227)
at
org.eclipse.jetty.util.log.JettyAwareLogger.log(JettyAwareLogger.java:619)
at
org.eclipse.jetty.util.log.JettyAwareLogger.debug(JettyAwareLogger.java:206)
at org.eclipse.jetty.util.log.Slf4jLog.debug(Slf4jLog.java:89)
at
org.eclipse.jetty.io.AbstractConnection.onClose(AbstractConnection.java:199)
at org.eclipse.jetty.server.HttpConnection.onClose(HttpConnection.java:482)
at
org.eclipse.jetty.io.SelectorManager.connectionClosed(SelectorManager.java:327)
at org.eclipse.jetty.io.ManagedSelector$2.run(ManagedSelector.java:431)
at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:213)
at
org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:147)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
at java.lang.Thread.run(Thread.java:745)
Tracing through the server code, the point of failure appears here in
org.eclipse.jetty.utl.BufferUtil.java in the function appendDebugString().
for (int i = buffer.position(); i < buffer.limit(); i++)
{
line 1042 >>> appendContentChar(buf,buffer.get(i));
if (i == buffer.position() + 16 && buffer.limit() >
buffer.position() + 32)
{
buf.append("...");
i = buffer.limit() - 16;
}
}
The 'buffer' in question is a java.nio.ByteBuffer which, according to this
dump, appears to have lost track of it's own internal state.
I have no idea what I could have done to provoke this. The errors were not
observed last week (the last time I ran the load-tests). They do not affect
the behaviour of the application proper but is wrecking havoc on
performance. This same script was giving me well over 8000 request per
second before this error appeared. Now, with request threads dying 1 time
per 100 requests, I can barely achieve 800 rps.
For those interested, the entire project can be found at
https://github.com/mdykman/jtl
My current development branch (the one this error is observed in) is
'deref'
--
- michael dykman
- [email protected]
May the Source be with you.
_______________________________________________
jetty-users mailing list
[email protected]
To change your delivery options, retrieve your password, or unsubscribe from
this list, visit
https://dev.eclipse.org/mailman/listinfo/jetty-users
