users@grizzly.java.net

RE: CPU Usage Profiling

From: Hasid Ronen <Ronen.Hasid_at_comverse.com>
Date: Tue, 16 Jun 2015 06:57:56 +0000

Hello,



It appears that due to design flaws in the hprof/visualvm the information presented by the tool is unreliable or just plain incorrect.

I suggest to use another tool to profile the application or attempt a test run with the following methods filtered out:



'java.net.SocketInputStream.socketRead0',

'java.net.SocketOutputStream.socketWrite0',

'java.net.PlainSocketImpl.socketAvailable',

'java.net.PlainSocketImpl.socketAccept',

'sun.nio.ch.EPollArrayWrapper.epollWait'



http://cp.mcafee.com/d/k-Kr6zqb3b35SjhOMCrKrjhpKCOyyCYrjhpKCOy-CYrjhpKOyYeupdBQjpISMUMMWevvW_8ELefzKLsKCOqenejsjosd7fbnjIyCGzt_BgY-F6lK1FJ4SyrKrKr0148_13o4o-h8YLx0-F74XEI5XK5XCzD17jeBXbdBW10-k29tKAE4iVdqdnu1NKdov0CUY2HEFY3uAurhjKMr0zjeCy0i2Mjd40M43Vg8Cy09QB0yq82qQqKCQPhOryhwfGfuY


Ronen.Hasid_at_Work 03-6454066
Ronen.Hasid_at_Orange 052-8544066
Ronen.Hasid_at_comverse.com

From: Broide Uri
Sent: Monday, June 15, 2015 8:17 PM
To: users_at_grizzly.java.net
Cc: Hasid Ronen; Tsukerman Dana
Subject: RE: CPU Usage Profiling

Hi Alexey,


1. We moved to latest JDK 8 and the results are the same.

2. We opened the Profiler as you requested (Java Classes included).

3. Note that we are working with Worker-thread IOStrategy

4. Attached is the Threads call stack of the Selectors (Note that is sorted by Time(CPU) and the Selectors Threads still utilizing most of the CPU)

As you can see from the Screenshot that the Selectors Threads are in the top of the list of the CPU consumers.
Any advice how to continue from here?

Thanks
Uri
[cid:image001.jpg_at_01D0A81A.68273380]

From: Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
Sent: Sunday, June 14, 2015 11:53 PM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Subject: Re: CPU Usage Profiling

Hi Uri,

looks like there is no selector spinning issue, so I suspect what you observe is normal... however if you want to investigate it more - you can profile your project including Java core classes, so we may see what exactly inside Grizzly select consumes CPU, I bet it's gonna be java.nio.Selector, but we can double check. Also you may want to run the same test on different jdk version, may be it will show you different result.

Thanks.

WBR,
Alexey.
On 14.06.15 13:24, Broide Uri wrote:
Hi Alexey,

The following is the profile data snapshot after stopping the load and wait much more time.
You can see that the select() method CPU consumption got back to 0.

Thanks
Uri

[cid:image004.jpg_at_01D0A6AD.5FC54060]


From: Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
Sent: Friday, June 12, 2015 1:38 AM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Subject: Re: CPU Usage Profiling

Hi Uri,

I saw you were using 1.7, just wanted to double check.
After stopping the load, can you check what is the CPU consumption rate of the server process?

Thanks.

WBR,
Alexey.
On 11.06.15 19:13, Broide Uri wrote:
Hi Alexey,

As requested, the following is the profile data snapshot after stopping the load and waiting till all connections were closed
BTW, we are running with JDK7 and not 6

Uri
[cid:image003.jpg_at_01D0A81A.68273380]

From: Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
Sent: Thursday, June 11, 2015 7:26 PM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Cc: Hasid Ronen; Tsukerman Dana
Subject: Re: CPU Usage Profiling

Hmm,

interesting, one more question, could you pls. check how the profile data look like when you stop loading the server.
So first you load the server, make sure that DefaultSelectorHandler consumes its 60%+ of CPU and then stop the load.

Can you pls. also double check that CPU consumption in general is low after you stop the server. Just want to make sure it's not related to selector spin problem observed with JDK 6.

Thanks.

WBR,
Alexey.
On 11.06.15 18:10, Broide Uri wrote:
As requested.
As you can see in the screenshot the select method on idle process is idle
[cid:image004.jpg_at_01D0A81A.68273380]

From: Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
Sent: Thursday, June 11, 2015 12:21 PM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Subject: Re: CPU Usage Profiling

Hi Uri,

can you pls. profile the server without loading at all to see the diff?
As I mentioned before, Selector.select(...) usually is reported as a hotspot, so I don't think your report is suspicious, but let's double check.

Thanks.

WBR,
Alexey.
On 11.06.15 09:22, Broide Uri wrote:
Hi Alexey,

Any update?

Thanks
Uri

From: Meltser Tiran [mailto:Tiran.Meltser_at_comverse.com]
Sent: Tuesday, June 09, 2015 7:56 PM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Subject: RE: CPU Usage Profiling
Importance: High

Hi Alexey,
We don't think this is the case as (I hope) you can see the graph is sorted by Self Time (CPU).

Tiran Meltser
System Architect
Global Products & Operations
Comverse - Making Your Network Smarter

T +972-3-7678381
M +972-54-5639381
Tiran.Meltser_at_comverse.com <mailto:Tiran.Meltser_at_comverse.com>
www.comverse.com<http://www.comverse.com/>
P Please think of the environment before printing this email

From: Oleksiy Stashok [mailto:oleksiy.stashok_at_oracle.com]
Sent: Tuesday, June 09, 2015 7:21 PM
To: users_at_grizzly.java.net<mailto:users_at_grizzly.java.net>
Subject: Re: CPU Usage Profiling

Hi Uri,

I suspect what you see is the total time spent inside the method, but most of the time it's in the idle state waiting for I/O events, so it shouldn't consume CPU.
Please let me know if it's not the case.

WBR,
Alexey.
On 09.06.15 16:29, Broide Uri wrote:
Hi Alexey,

After stabilizing on 100% Success Rate in heavy load on our application we started to perform CPU Usage profiling.
We have noticed (you can see the attached screenshot) that we are spending 66% from the CPU time in the org.glassfish.nio.DefaultSelectorHandler.select() method.
We are running the load with the following environment:

* Grizzly 2.3.21

* JDK 1.7.0_72-b14

* RHEL 5.X

Any advice on how can we improve the high CPU consumption?

[cid:image003.jpg_at_01D0A2D6.6204FEE0]

Thanks
Uri

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."
________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com<mailto:security_at_comverse.com>. Thank You."

________________________________
"This e-mail message may contain confidential, commercial or privileged information that constitutes proprietary information of Comverse Inc. or its subsidiaries. If you are not the intended recipient of this message, you are hereby notified that any review, use or distribution of this information is absolutely prohibited and we request that you delete all copies and contact us by e-mailing to: security_at_comverse.com. Thank You."




image001.jpg
(image/jpeg attachment: image001.jpg)

image002.jpg
(image/jpeg attachment: image002.jpg)

image003.jpg
(image/jpeg attachment: image003.jpg)

image004.jpg
(image/jpeg attachment: image004.jpg)

image005.jpg
(image/jpeg attachment: image005.jpg)