Jetty Comet clients start to poll the server

90 views
Skip to first unread message

valli nanduri

unread,
Feb 18, 2015, 1:51:53 AM2/18/15
to comet...@googlegroups.com

I am running Websockets on Jetty 9.2.7 with Cometd 3.

When the client (browser) starts, the sockets work fine for sometime and suddenly on some event they start to poll. 

It accepts HTTP requests at this stage and I have noticed it accepts new sockets also but not sure why the other clients poll instead of holding on to the connection.

How can we prevent this? This is literally killing my application behavior.

We get about 300,000 requests a day. Here is the server configuration:

minThreads : 100, maxThreads : 1500, acceptors: default , idleTimeout: 60000

open files can be 65535. Other OS configuration as per Jetty documentation look fine.

net.core.rmem_max = 212992

net.core.wmem_max = 212992

net.ipv4.tcp_rmem = 4096        87380   6291456
net.ipv4.tcp_wmem = 4096        16384   4194304
net.core.somaxconn = 4096

I enabled server dump but could not find much of a clue. It does not look like a problem with Load because the server's behavior is not consistent.

If you look at the number of requests we were getting till 9.31, it was in 100s. The sudden spike in the number is because the clients started to poll. Its certain that the server will stop responding in some time.

What is interesting is, in the peak hours, the numbers look a lot different. The server starts to poll upon 3000+ requests.

We get some requests that are taking 18 seconds to complete. We get about 20,000 of them a day.Some requests take 5 seconds to complete and we get about 200,000 of such requests a day. Could the requests with high latency be causing the problem? Even if that does, The frequency of high latency requests is way more compared to what is shown in the screenshot. But the server stands them for a really long time than what just happened?

What is the problem? The Code? the server? Server Configuration? I am totally lost and we are considering to change the platform as the same code worked with no issues on jetty 8 a couple of months ago. This is the situation ever since we migrated.

Please suggest.

Thanks! 

Simone Bordet

unread,
Feb 18, 2015, 3:03:52 AM2/18/15
to cometd-dev
Hi,

On Wed, Feb 18, 2015 at 7:51 AM, valli nanduri <val...@gmail.com> wrote:
>
> I am running Websockets on Jetty 9.2.7 with Cometd 3.
>
> When the client (browser) starts, the sockets work fine for sometime and suddenly on some event they start to poll.

How do you know you're using WebSocket ?
Polling is a feature that the WebSocket transport does *not* have; it
belongs to the HTTP transport.

The HTTP transport performs a kind of polling called "long-polling".
If your server emits a lot of messages to all the connected clients,
these will likely be delivered via the "long-poll" and therefore look
like normal polling.

What clients do you use ? Browsers ? What vendor / versions ?

> It accepts HTTP requests at this stage and I have noticed it accepts new sockets also but not sure why the other clients poll instead of holding on to the connection.

There is a mode, when the client is a browser, called "multiple
sessions" or "multiple-clients":
http://docs.cometd.org/3/reference/#_java_server_multiple_sessions
Perhaps you're hitting that ?

> How can we prevent this? This is literally killing my application behavior.
>
> We get about 300,000 requests a day. Here is the server configuration:
>
> minThreads : 100, maxThreads : 1500, acceptors: default , idleTimeout: 60000
>
> open files can be 65535. Other OS configuration as per Jetty documentation look fine.
>
> net.core.rmem_max = 212992
>
> net.core.wmem_max = 212992
>
> net.ipv4.tcp_rmem = 4096 87380 6291456
> net.ipv4.tcp_wmem = 4096 16384 4194304
> net.core.somaxconn = 4096
>
> I enabled server dump but could not find much of a clue. It does not look like a problem with Load because the server's behavior is not consistent.
>
> If you look at the number of requests we were getting till 9.31, it was in 100s. The sudden spike in the number is because the clients started to poll. Its certain that the server will stop responding in some time.
>
> What is interesting is, in the peak hours, the numbers look a lot different. The server starts to poll upon 3000+ requests.
>
> We get some requests that are taking 18 seconds to complete. We get about 20,000 of them a day.Some requests take 5 seconds to complete and we get about 200,000 of such requests a day. Could the requests with high latency be causing the problem? Even if that does, The frequency of high latency requests is way more compared to what is shown in the screenshot. But the server stands them for a really long time than what just happened?
>

Have you read this: http://docs.cometd.org/3/reference/#_concepts_threading ?

> What is the problem? The Code? the server? Server Configuration? I am totally lost and we are considering to change the platform as the same code worked with no issues on jetty 8 a couple of months ago. This is the situation ever since we migrated.
>

Between Jetty 8 and Jetty 9 the WebSocket implementation was rewritten
to adhere to the WebSocket standards.
It may be that your clients are still "old" WebSocket clients that
cause Jetty 9 to reject the WebSocket upgrade ?

> Please suggest.

Please enable CometD client debug, and see what's going on.

In general, to understand what's happening we need to know a bit more
about what your application does, isolate the behavior of a "bad"
client, and study that.
See http://docs.cometd.org/3/reference/#_troubleshooting

--
Simone Bordet
----
http://cometd.org
http://webtide.com
http://intalio.com
Developer advice, training, services and support
from the Jetty & CometD experts.
Intalio, the modern way to build business applications.

valli nanduri

unread,
Feb 18, 2015, 4:12:10 AM2/18/15
to comet...@googlegroups.com
Hi Simone,
 
When I go to my browser (Chrome) and see the network tab, with Websockets filter, I see Webscokets running from my web page to our server.So, it sure does connect via web sockets.

But the same page starts to send /comet/connect requests to server indefinitely 100s of times a second to the server - that makes me think they are polling.

The App is a chat application.

I am looking into the links you gave me right now. And For now, I am going to disable webscokets on all the clients and fall back to Cometd to see if that makes any difference. 

I will circle back after going through the documentation.

Thanks!

Simone Bordet

unread,
Feb 18, 2015, 4:55:02 AM2/18/15
to cometd-dev
Hi,

On Wed, Feb 18, 2015 at 10:12 AM, valli nanduri <val...@gmail.com> wrote:
>
> Hi Simone,
>
> When I go to my browser (Chrome) and see the network tab, with Websockets filter, I see Webscokets running from my web page to our server.So, it sure does connect via web sockets.
>
> But the same page starts to send /comet/connect requests to server indefinitely 100s of times a second to the server - that makes me think they are polling.

One CometD client does not send hundreds of requests per second to the
server, unless the server is sending hundreds of messages per second
to the client, so I am not sure what you mean here.
Enable debug logging on the client, and look at the browser console:
you should have a detailed log of what the CometD client is doing.

valli nanduri

unread,
Feb 19, 2015, 4:14:41 PM2/19/15
to comet...@googlegroups.com

Hi Simone!

I think I am lost and not sure how to describe the problem. I was initially wrong when  I posted this problem. I dont see the websokets really polling.

I looked at the post you shared (http://docs.cometd.org/3/reference/#_concepts_threading ? ) and I implemented the same in all the Listeners. It seemed to have soothed the problem.

However, What I find now in the server thread dump is hundreds of the following logs. Apart from that, some of our code has some Synchronized methods and all those methods go to Blocked state at one point that is effecting the application behavior.

Everytime the server is dead, when I looked at the server dump, there are a bunch of Idle threads and blocked threads in the code. All the times, the entire thread dump has only ONE of those synchronized methods in blocked state. Looks like All these IDLE threads are waiting for the Blocked Synchronized thread to get into runnable state and complete executing?


 |   +- 158 qtp364089744-158 TIMED_WAITING IDLE

 |   +- 159 qtp364089744-159 TIMED_WAITING IDLE

 |   +- 160 qtp364089744-160 TIMED_WAITING IDLE

 |   +- 162 qtp364089744-162 TIMED_WAITING IDLE


Now, What I am confused about is, before I see all these IDLE threads in the dump, I see a huge amount of socket timeout exceptions!  How do I interpret the problem? The Socket timeouts are because of the IDLE Threads? Or IDLE threads are beacuse of Socket timeouts?

This is happening on our production server and I am confused at this cross roads! Any suggestion would be greatly helpful.

java.net.SocketTimeoutException: Timeout on Read

at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onReadTimeout(AbstractWebSocketConnection.java:526)

at org.eclipse.jetty.io.AbstractConnection.onFillInterestedFailed(AbstractConnection.java:173)

at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillInterestedFailed(AbstractWebSocketConnection.java:496)

at org.eclipse.jetty.io.AbstractConnection$ReadCallback$1.run(AbstractConnection.java:582)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)

at java.lang.Thread.run(Thread.java:745)

Thank you!

On Wednesday, 18 February 2015 12:21:53 UTC+5:30, valli nanduri wrote:

Simone Bordet

unread,
Feb 19, 2015, 4:29:16 PM2/19/15
to cometd-dev
Hi,

On Thu, Feb 19, 2015 at 10:14 PM, valli nanduri <val...@gmail.com> wrote:
> Hi Simone!
>
> I think I am lost and not sure how to describe the problem. I was initially wrong when I posted this problem. I dont see the websokets really polling.

Ok.

> I looked at the post you shared (http://docs.cometd.org/3/reference/#_concepts_threading ? ) and I implemented the same in all the Listeners. It seemed to have soothed the problem.

Cool.

> However, What I find now in the server thread dump is hundreds of the following logs. Apart from that, some of our code has some Synchronized methods and all those methods go to Blocked state at one point that is effecting the application behavior.

So you have a deadlock of some sort in your application.

> Everytime the server is dead, when I looked at the server dump, there are a bunch of Idle threads and blocked threads in the code. All the times, the entire thread dump has only ONE of those synchronized methods in blocked state. Looks like All these IDLE threads are waiting for the Blocked Synchronized thread to get into runnable state and complete executing?
>
>
> | +- 158 qtp364089744-158 TIMED_WAITING IDLE
>
> | +- 159 qtp364089744-159 TIMED_WAITING IDLE
>
> | +- 160 qtp364089744-160 TIMED_WAITING IDLE
>
> | +- 162 qtp364089744-162 TIMED_WAITING IDLE

This is completely normal.
These are Jetty threads waiting idle in the thread pool.

> Now, What I am confused about is, before I see all these IDLE threads in the dump, I see a huge amount of socket timeout exceptions! How do I interpret the problem? The Socket timeouts are because of the IDLE Threads? Or IDLE threads are beacuse of Socket timeouts?

If your server hangs because of application deadlocks, then the
connections to the client will eventually be closed by Jetty because
they are idle.
It's normal behavior for a server: if a connection is not used, it
will close it after an idle timeout.

You just need to fix your application deadlocks, there is nothing
wrong in Jetty or CometD from what you report.
Good luck !

valli nanduri

unread,
Feb 19, 2015, 5:01:35 PM2/19/15
to comet...@googlegroups.com
Hi Simone!

Thank you for Confirming its nothing to do with the Jetty or Cometd. 

The same code worked on Jetty 8.1.0 though! Thats what made me reach here.  I will post here once I figure out what fixed it! Thank you for your time!



On Wednesday, 18 February 2015 12:21:53 UTC+5:30, valli nanduri wrote:

valli nanduri

unread,
Mar 5, 2015, 2:54:43 PM3/5/15
to comet...@googlegroups.com
Hi!

I have been working on trying to solve the problem but I have no luck as of yet!

The Problem does not really seem like its in my code!

I see weird symptoms. I upgraded to jetty 9.2.9 to see if that helps but no luck. 

I see hundreds of TIMED_WAITING threads also! 

 |   +- 544 qtp173911631-544 TIMED_WAITING @ sun.misc.Unsafe.park(Native Method) IDLE

 |   +- 545 qtp173911631-545 TIMED_WAITING @ sun.misc.Unsafe.park(Native Method) IDLE


And I see the below exception.  I have not seen the below exception before! 

2015-03-05 10:04:15.972:WARN:oejs.ServletHandler:qtp173911631-549: /js/cometd3/jquery/jquery-2.1.1.js

java.io.IOException: org.eclipse.jetty.util.SharedBlockingCallback$BlockerTimeoutException

at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:234)

at org.eclipse.jetty.server.HttpOutput.sendContent(HttpOutput.java:572)

at org.eclipse.jetty.servlet.DefaultServlet.sendData(DefaultServlet.java:955)

at org.eclipse.jetty.servlet.DefaultServlet.doGet(DefaultServlet.java:533)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)

at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:224)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)

at org.eclipse.jetty.server.Server.handle(Server.java:497)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)

at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)

at java.lang.Thread.run(Thread.java:745)

Caused by: 

org.eclipse.jetty.util.SharedBlockingCallback$BlockerTimeoutException

at org.eclipse.jetty.util.SharedBlockingCallback$Blocker.block(SharedBlockingCallback.java:216)

at org.eclipse.jetty.server.HttpOutput.sendContent(HttpOutput.java:572)

at org.eclipse.jetty.servlet.DefaultServlet.sendData(DefaultServlet.java:955)

at org.eclipse.jetty.servlet.DefaultServlet.doGet(DefaultServlet.java:533)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:687)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669)

at org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:224)

at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)

at org.eclipse.jetty.server.Server.handle(Server.java:497)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)

at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)

at java.lang.Thread.run(Thread.java:745)


Simone Bordet

unread,
Mar 5, 2015, 3:34:26 PM3/5/15
to cometd-dev
Hi,

On Thu, Mar 5, 2015 at 8:54 PM, valli nanduri <val...@gmail.com> wrote:
>
> Hi!
>
> I have been working on trying to solve the problem but I have no luck as of yet!
>
> The Problem does not really seem like its in my code!
>
> I see weird symptoms. I upgraded to jetty 9.2.9 to see if that helps but no luck.
>
> I see hundreds of TIMED_WAITING threads also!
>
> | +- 544 qtp173911631-544 TIMED_WAITING @ sun.misc.Unsafe.park(Native Method) IDLE
>
> | +- 545 qtp173911631-545 TIMED_WAITING @ sun.misc.Unsafe.park(Native Method) IDLE

Totally normal, these threads are idle in the Jetty thread pool.

> And I see the below exception. I have not seen the below exception before!
>
> 2015-03-05 10:04:15.972:WARN:oejs.ServletHandler:qtp173911631-549: /js/cometd3/jquery/jquery-2.1.1.js
>
> java.io.IOException: org.eclipse.jetty.util.SharedBlockingCallback$BlockerTimeoutException

Your client is not reading the response content of a static file.
This is typically an indication that you have network issues.
Reply all
Reply to author
Forward
0 new messages