You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Bob DeRemer <bo...@thingworx.com> on 2013/12/13 14:12:08 UTC

high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?

Hi Mark (et al),

We're seeing really high CPU utilization with just a 1000 active websockets that are sending/receiving 100 byte binary messages.   The profiling snippet below was with 1000 connections.  If we start to increase the number of connections, the time spent in the NIO logic starts to consume the majority of the processing.  As a result, I'm trying to verify:


*         Is this something that can be tuned/improved using Tomcat's NIO settings?

*         Is this a bug in Tomcat 7 (websocket/NIO)?

*         Are we hitting some issue with 1000+ highly active NIO sockets?

The nature of this application is that it's primary functionality is to process binary messages on (ideally 10 - 20K websockets), forward them to another server for processing, then send the responses back.  As a result, the performance of the websocket communication is a critical factor for success.

Please let me know if you'd like to discuss this - I'm available any time.

Thanks,
Bob


We have been profiling this in YourKit and as we increase the number of websockets, naturally we see the CPU utilization increase.  The concern is that we're seeing this at what seems to be a fairly low number of websockets.  The YourKit profiling showed 41% of the time being spent in the following code.  My apologies for the formatting.  I can provide an attachment out-of-band if it would be helpful.

|      +---org.apache.tomcat.util.net.NioEndpoint$Poller.run()                                                    |  38,594   41 %  |              0  |
|      | |                                                                                                        |                 |                 |
|      | +---sun.nio.ch.SelectorImpl.select(long)                                                                 |  25,615   27 %  |              0  |
|      | | |                                                                                                      |                 |                 |
|      | | +---sun.nio.ch.SelectorImpl.lockAndDoSelect(long)                                                      |  25,615   27 %  |              0  |
|      | |   |                                                                                                    |                 |                 |
|      | |   +---sun.nio.ch.WindowsSelectorImpl.doSelect(long)                                                    |  25,615   27 %  |             46  |
|      | |     |                                                                                                  |                 |                 |
|      | |     +---sun.nio.ch.WindowsSelectorImpl.resetWakeupSocket()                                             |  13,681   14 %  |          1,107  |
|      | |     |                                                                                                  |                 |                 |
|      | |     +---sun.nio.ch.WindowsSelectorImpl$StartLock.access$300(WindowsSelectorImpl$StartLock)             |  10,826   11 %  |              0  |
|      | |     |                                                                                                  |                 |                 |
|      | |     +---sun.nio.ch.WindowsSelectorImpl.updateSelectedKeys()                                            |   1,029    1 %  |              0  |
|      | |     |                                                                                                  |                 |                 |
|      | |     +---sun.nio.ch.SelectorImpl.processDeregisterQueue()                                               |      31    0 %  |              0  |
|      | |                                                                                                        |                 |                 |
|      | +---org.apache.tomcat.util.net.NioEndpoint$Poller.processKey(SelectionKey, NioEndpoint$KeyAttachment)    |  11,996   13 %  |             31  |
|      | | |                                                                                                      |                 |                 |
|      | | +---org.apache.tomcat.util.net.NioEndpoint.processSocket(NioChannel, SocketStatus, boolean)            |  11,778   12 %  |              0  |
|      | | | |                                                                                                    |                 |                 |
|      | | | +---org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(Runnable)                              |  11,746   12 %  |              0  |
|      | | | | |                                                                                                  |                 |                 |
|      | | | | +---org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(Runnable, long, TimeUnit)            |  11,746   12 %  |              0  |
|      | | | |   |                                                                                                |                 |                 |
|      | | | |   +---java.util.concurrent.ThreadPoolExecutor.execute(Runnable)                                    |  11,746   12 %  |             15  |
|      | | | |     |                                                                                              |                 |                 |
|      | | | |     +---org.apache.tomcat.util.threads.TaskQueue.offer(Object)                                     |  11,731   12 %  |              0  |
|      | | | |       |                                                                                            |                 |                 |
|      | | | |       +---org.apache.tomcat.util.threads.TaskQueue.offer(Runnable)                                 |  11,731   12 %  |             46  |
|      | | | |         |                                                                                          |                 |                 |
|      | | | |         +---java.util.concurrent.LinkedBlockingQueue.offer(Object)                                 |  11,668   12 %  |             15  |









Bob DeRemer
Senior Director, Architecture and Development

[Description: Description: Description: Description: cid:image001.png@01CBE3DE.51A12030]
http://www.thingworx.com<http://www.thingworx.com/>
Skype: bob.deremer.thingworx
O: 610.594.6200 x812
M: 717.881.3986


Re: high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?

Posted by Christopher Schultz <ch...@christopherschultz.net>.
-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Bob,

On 12/13/13, 8:12 AM, Bob DeRemer wrote:
> Hi Mark (et al),

While Mark is one of the most likely to respond, please address your
questions only to the community.... at least at first ;)

> We’re seeing really high CPU utilization with just a 1000 active 
> websockets that are sending/receiving 100 byte binary messages.
> The profiling snippet below was with 1000 connections.  If we start
> to increase the number of connections, the time spent in the NIO
> logic starts to consume the majority of the processing.

For those trying to play-along at home (who haven't been keeping their
configuration up-to-date with yours), what is your current <Connector>
configuration?

How are you observing CPU usage? Do you have thread dumps and/or
profiling data you can share with us?

- -chris
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.15 (Darwin)
Comment: GPGTools - http://gpgtools.org
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBCAAGBQJSq5W4AAoJEBzwKT+lPKRY5BcQAJFEinaGtvPUs+AyNkZ45Agf
go6esNq1xmKVejLq899KxeF+kPGfBUO3e8WO4abYiz5S1bd0Sqfo9I9i5h1EF7bg
HupcRlGKFrq3/YlCwe49QFkShk3CMCx6MtlWmoTbeL4ZNKkKQFDMbQDreJ3Gj8pd
pwkR8CFg/MvGPJWrhBRNOh9/mP+1tUfOizyLpr9qC9pPJ3X42IuocsFuhZ9uiGNv
gdOgfBI85XaIefuKWUlzTnqovozhQcLtpg3brsbhF6RxL92SYBE2aSPz53378B2H
/4KwnTkISJdLObm9/k1qxigQroJ0GOsaTpqoEYdhbNn9YYKovaKYM4c3hehS6QfA
wx1rwtN4j/t8T96W/Rp7UrL0uxmRwvs+QJB1lDWTD4+Cp0elsTgDU91K3b9r8I64
ZnG7Z4Kep2x23ybcnksMvgzQvQiUntaUY4Q44cF0FTw5S0+hCD8t7ov3mMl4IrHX
2y+rRkgylNi2wiDOI5XHPQB/UYG3FmDy9hSce68jqvmy9gGOBmt7kcKsxaVvRqaJ
WXX97SLL91gNbVZ0UY1X5N18C0X/Hr4p8LYJ6hDf8L4JAgO8wVGGjPrFY3GvHxXv
S+W3JOKqo9jCukWhdPTmxVGfWWEuvv3LoYZ3d0yaHdMvojq9bfMYW8rCU1+1x+HT
QOkC/NVl2a5doe3qCWwL
=wv12
-----END PGP SIGNATURE-----

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?

Posted by David kerber <dc...@verizon.net>.
On 12/13/2013 8:12 AM, Bob DeRemer wrote:
> Hi Mark (et al),
>
> We’re seeing really high CPU utilization with just a 1000 active
> websockets that are sending/receiving 100 byte binary messages.   The
> profiling snippet below was with 1000 connections.  If we start to
> increase the number of connections, the time spent in the NIO logic
> starts to consume the majority of the processing.  As a result, I’m
> trying to verify:

How many cores does your cpu have?  You might be thrashing your cpu with 
excessive context switching because of the large number of threads.  If 
that's the case, then throwing more lower-power cores at it may be of use.


>
> ·Is this something that can be tuned/improved using Tomcat’s NIO settings?
>
> ·Is this a bug in Tomcat 7 (websocket/NIO)?
>
> ·Are we hitting some issue with 1000+ highly active NIO sockets?
>
> The nature of this application is that it’s primary functionality is to
> process binary messages on (ideally 10 – 20K websockets), forward them
> to another server for processing, then send the responses back.  As a
> result, the performance of the websocket communication is a critical
> factor for success.
>
> Please let me know if you’d like to discuss this – I’m available any time.
>
> Thanks,
>
> Bob
>
> We have been profiling this in YourKit and as we increase the number of
> websockets, naturally we see the CPU utilization increase.  The concern
> is that we’re seeing this at what seems to be a fairly low number of
> websockets.  The YourKit profiling showed 41% of the time being spent in
> the following code.  My apologies for the formatting.  I can provide an
> attachment out-of-band if it would be helpful.
>
> |
> +---org.apache.tomcat.util.net.NioEndpoint$Poller.run()
> |  38,594   41 %  |              0  |
>
> |      | |
>                                            |
> |                 |
>
> |      |
> +---sun.nio.ch.SelectorImpl.select(long)
> |  25,615   27 %  |              0  |
>
> |      | | |
>                                                                                            |                 |                 |
>
> |      | |
> +---sun.nio.ch.SelectorImpl.lockAndDoSelect(long)
> |  25,615   27 %  |              0  |
>
> |      | |
> |
> |                 |                 |
>
> |      | |
> +---sun.nio.ch.WindowsSelectorImpl.doSelect(long)
>                                    |  25,615   27 %  |             46  |
>
> |      | |
> |
> |                 |                 |
>
> |      | |
> +---sun.nio.ch.WindowsSelectorImpl.resetWakeupSocket()
> |  13,681   14 %  |          1,107  |
>
> |      | |
> |
> |                 |                 |
>
> |      | |
> +---sun.nio.ch.WindowsSelectorImpl$StartLock.access$300(WindowsSelectorImpl$StartLock)
> |  10,826   11 %  |              0  |
>
> |      | |
> |
>                            |                 |                 |
>
> |      | |
> +---sun.nio.ch.WindowsSelectorImpl.updateSelectedKeys()
> |   1,029    1 %  |              0  |
>
> |      | |     |
>                                                                            |                 |                 |
>
> |      | |
> +---sun.nio.ch.SelectorImpl.processDeregisterQueue()
> |      31    0 %  |              0  |
>
> |      |
> |
> |                 |                 |
>
> |      |
> +---org.apache.tomcat.util.net.NioEndpoint$Poller.processKey(SelectionKey,
> NioEndpoint$KeyAttachment)    |  11,996   13 %  |             31  |
>
> |      | |
> |
> |                 |                 |
>
> |      | |
> +---org.apache.tomcat.util.net.NioEndpoint.processSocket(NioChannel,
> SocketStatus, boolean)            |  11,778   12 %  |              0  |
>
> |      | | |
> |
>            |                 |                 |
>
> |      | | |
> +---org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(Runnable)
> |  11,746   12 %  |              0  |
>
> |      | | | | |
>                                                            |                 |                 |
>
> |      | | | |
> +---org.apache.tomcat.util.threads.ThreadPoolExecutor.execute(Runnable,
> long, TimeUnit)            |  11,746   12 %  |              0  |
>
> |      | | | |
> |
> |                 |                 |
>
> |      | | | |
> +---java.util.concurrent.ThreadPoolExecutor.execute(Runnable)
>    |  11,746   12 %  |             15  |
>
> |      | | | |
> |
> |                 |                 |
>
> |      | | | |
> +---org.apache.tomcat.util.threads.TaskQueue.offer(Object)
> |  11,731   12 %  |              0  |
>
> |      | | | |
> |
> |                 |                 |
>
> |      | | | |
>       +---org.apache.tomcat.util.threads.TaskQueue.offer(Runnable)                                 |  11,731   12 %  |             46  |
>
> |      | | | |
> |
> |                 |                 |
>
> |      | | | |
> +---java.util.concurrent.LinkedBlockingQueue.offer(Object)
> |  11,668   12 %  |             15  |
>
> *Bob DeRemer*
>
> *Senior Director, Architecture and Development*
>
> Description: Description: Description: Description:
> cid:image001.png@01CBE3DE.51A12030
>
> http://www.thingworx.com <http://www.thingworx.com/>
>
> Skype: bob.deremer.thingworx
>
> O: 610.594.6200 x812
>
> M: 717.881.3986
>


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?

Posted by Bob DeRemer <bo...@thingworx.com>.

> -----Original Message-----
> From: Mark Thomas [mailto:markt@apache.org]
> Sent: Saturday, December 14, 2013 9:06 AM
> To: Tomcat Users List
> Subject: Re: high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?
> 
> On 13/12/2013 13:12, Bob DeRemer wrote:
> > We have been profiling this in YourKit and as we increase the number
> > of websockets, naturally we see the CPU utilization increase.  The
> > concern is that we're seeing this at what seems to be a fairly low
> > number of websockets.  The YourKit profiling showed 41% of the time
> > being spent in the following code.  My apologies for the formatting.
> > I can provide an attachment out-of-band if it would be helpful.
> 
> I've seen similar figures from YourKit when testing with just a single
> connection. There does seem to be a lot of time spent in the NIO Poller code.
> 
> When I looked at it last time nothing immediately obvious jumped out at me in
> terms of something that could be changed to improve things. It needs some
> more time spent on a deeper analysis. That is on my TODO list. If any NIO
> experts want to take a look and make some suggestions that would be great.
> 
> As an aside, as much as I like YourKit, you do have to be careful (as you do with
> any profiler) when stress testing that the profiler isn't distorting the results. I
> have been led down the wrong path a few times when I wasn't careful enough.
> 

I have noticed about a 20% reduction in performance using Yourkit in it's least intrusive mode.  Thanks for the input and suggestions.  If I find out anything additional, I'll post it.

Thx, bob

> Mark
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: high CPU usage with NIO and 1000+ websockets on Tomcat 7.0.49?

Posted by Mark Thomas <ma...@apache.org>.
On 13/12/2013 13:12, Bob DeRemer wrote:
> We have been profiling this in YourKit and as we increase the number of
> websockets, naturally we see the CPU utilization increase.  The concern
> is that we’re seeing this at what seems to be a fairly low number of
> websockets.  The YourKit profiling showed 41% of the time being spent in
> the following code.  My apologies for the formatting.  I can provide an
> attachment out-of-band if it would be helpful.  

I've seen similar figures from YourKit when testing with just a single
connection. There does seem to be a lot of time spent in the NIO Poller
code.

When I looked at it last time nothing immediately obvious jumped out at
me in terms of something that could be changed to improve things. It
needs some more time spent on a deeper analysis. That is on my TODO
list. If any NIO experts want to take a look and make some suggestions
that would be great.

As an aside, as much as I like YourKit, you do have to be careful (as
you do with any profiler) when stress testing that the profiler isn't
distorting the results. I have been led down the wrong path a few times
when I wasn't careful enough.

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org