Jetty

BayeuxClient EofException when under moderate load

Details

  • Type: Bug Bug
  • Status: Resolved Resolved
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: 7.2.0
  • Fix Version/s: 7.5.1
  • Component/s: Bayeux
  • Labels:
    None
  • Environment:
    I am using jetty 7.2.0, cometd 1.1.3, java 1.6.0_22 (Win XP, Mac OS X , Linux all exhibit same problem).
  • Number of attachments :
    2

Description

I'm writing a test harness to load test our cometd implementation. Using 1x HttpClient (32 threads) and a configurable number of BayeuxClient. I can readily reproduce the issue with a small number of clients (have seen with only 10 clients, gets worse with more clients). Each client subscribes to < 7 channels, and the server side is generating about 1 message per channel per second. JVM is given 1GB heap.

I've setup the test harness to create BayeuxClient only once every 5 seconds so it really is being quite gentle. Have seen problem with as few as 10 BayeuxCLient started.

org.eclipse.jetty.io.EofException
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:319)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212)
at org.eclipse.jetty.client.HttpConnection.handle(HttpConnection.java:262)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:510)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:450)
at java.lang.Thread.run(Unknown Source)
Caused by: org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.unwrap(SslSelectChannelEndPoint.java:693)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.fill(SslSelectChannelEndPoint.java:323)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:290)
... 7 more

Here are some stats from our test harness showing summary every 30s:
29/11/10 07:40:04,738 INFO [FelixBasherEventCoordinator] Connection: good/sec=3.17 attempted=95 failed=0 expired=0 exceptions=0
29/11/10 07:40:34,739 INFO [FelixBasherEventCoordinator] Connection: good/sec=9.43 attempted=284 failed=0 expired=0 exceptions=1
29/11/10 07:41:04,739 INFO [FelixBasherEventCoordinator] Connection: good/sec=14.53 attempted=436 failed=0 expired=0 exceptions=0
29/11/10 07:41:34,739 INFO [FelixBasherEventCoordinator] Connection: good/sec=10.03 attempted=311 failed=0 expired=0 exceptions=10
29/11/10 07:42:04,740 INFO [FelixBasherEventCoordinator] Connection: good/sec=16.43 attempted=493 failed=0 expired=0 exceptions=0
29/11/10 07:42:34,740 INFO [FelixBasherEventCoordinator] Connection: good/sec=18.13 attempted=553 failed=0 expired=0 exceptions=9
29/11/10 07:43:04,741 INFO [FelixBasherEventCoordinator] Connection: good/sec=12.20 attempted=395 failed=0 expired=0 exceptions=29
29/11/10 07:43:34,741 INFO [FelixBasherEventCoordinator] Connection: good/sec=14.40 attempted=443 failed=0 expired=1 exceptions=10
29/11/10 07:44:04,742 INFO [FelixBasherEventCoordinator] Connection: good/sec=31.17 attempted=935 failed=0 expired=0 exceptions=0
29/11/10 07:44:34,742 INFO [FelixBasherEventCoordinator] Connection: good/sec=32.77 attempted=983 failed=0 expired=0 exceptions=0
29/11/10 07:45:04,743 INFO [FelixBasherEventCoordinator] Connection: good/sec=10.70 attempted=350 failed=0 expired=0 exceptions=29
29/11/10 07:45:34,744 INFO [FelixBasherEventCoordinator] Connection: good/sec=16.40 attempted=513 failed=0 expired=0 exceptions=21
29/11/10 07:46:04,745 INFO [FelixBasherEventCoordinator] Connection: good/sec=9.03 attempted=313 failed=0 expired=0 exceptions=42
29/11/10 07:46:34,752 INFO [FelixBasherEventCoordinator] Connection: good/sec=22.49 attempted=684 failed=0 expired=0 exceptions=9
29/11/10 07:47:04,752 INFO [FelixBasherEventCoordinator] Connection: good/sec=13.03 attempted=402 failed=0 expired=10 exceptions=1

  1. Java Source File
    jettyEOFSample.java
    29/Jan/11 6:22 AM
    2 kB
    Maxim Veksler
  2. Java Source File
    jettyEOFSample.java
    29/Jan/11 6:20 AM
    2 kB
    Maxim Veksler

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Greg Wilkins added a comment -

Hey Damian!

Does this exception stop the client working?

Is the exception reported as a warn or a debug?

Show
Greg Wilkins added a comment - Hey Damian! Does this exception stop the client working? Is the exception reported as a warn or a debug?
Hide
Permalink
Greg Wilkins added a comment -

Also if you could make some test case code available, that would be very helpful

Show
Greg Wilkins added a comment - Also if you could make some test case code available, that would be very helpful
Hide
Permalink
Damian Carter added a comment -

G'day Greg.

Sorry for late reply. Flat out as usual. You know how it is...
The client is able to recover from this error. Will check what the log level is.

Show
Damian Carter added a comment - G'day Greg. Sorry for late reply. Flat out as usual. You know how it is... The client is able to recover from this error. Will check what the log level is.
Hide
Permalink
Maxim Veksler added a comment -

Hello,

I'm also seething exception (logback log format

14:07:30.315 [qtp1288022528-19] DEBUG org.eclipse.jetty.util.log - EOF
org.eclipse.jetty.io.EofException: null
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:319) ~[jetty-http-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212) ~[jetty-http-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:426) ~[jetty-server-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:508) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205]
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:451) [jetty-util-7.2.2.v20101205.jar:7.2.2.v20101205]
at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22]

No load. Always reproducible... Not interfering with the reply, client is getting the expected answer.

Sample code following.

Show
Maxim Veksler added a comment - Hello, I'm also seething exception (logback log format 14:07:30.315 [qtp1288022528-19] DEBUG org.eclipse.jetty.util.log - EOF org.eclipse.jetty.io.EofException: null at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:319) ~ [jetty-http-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:212) ~ [jetty-http-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:426) ~ [jetty-server-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:508) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.io.nio.SelectChannelEndPoint.access$000(SelectChannelEndPoint.java:34) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:40) [jetty-io-7.2.2.v20101205.jar:7.2.2.v20101205] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:451) [jetty-util-7.2.2.v20101205.jar:7.2.2.v20101205] at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22] No load. Always reproducible... Not interfering with the reply, client is getting the expected answer. Sample code following.
Hide
Permalink
Maxim Veksler added a comment -

Production code that is causing the problem, obscured.

Show
Maxim Veksler added a comment - Production code that is causing the problem, obscured.
Hide
Permalink
Maxim Veksler added a comment - - edited

sorry, please ignore/delete.

Show
Maxim Veksler added a comment - - edited sorry, please ignore/delete.
Hide
Permalink
Simone Bordet added a comment -

The latest versions of Jetty have improved half closes and idle timeout handling, which could have been causes of the errors reported.

Also SSL has been substantially refactored, especially in the upcoming Jetty 7.5.2 version.

I have been running SSL tests with recent CometD versions without problems, so I think this bug has been fixed by code improvements present in recent Jetty versions.

I am closing this bug, but by all means please reopen it if latest Jetty versions still produce the error, along with exact steps to reproduce.

Show
Simone Bordet added a comment - The latest versions of Jetty have improved half closes and idle timeout handling, which could have been causes of the errors reported. Also SSL has been substantially refactored, especially in the upcoming Jetty 7.5.2 version. I have been running SSL tests with recent CometD versions without problems, so I think this bug has been fixed by code improvements present in recent Jetty versions. I am closing this bug, but by all means please reopen it if latest Jetty versions still produce the error, along with exact steps to reproduce.

People

  • Assignee:
    Simone Bordet
    Reporter:
    Damian Carter
Vote (0)
Watch (0)

Dates

  • Created:
    Updated:
    Resolved: