Re: How do I read the output of the Pulse Logger?

[Scott Palmer]

In my test I’m running the same application on Windows and Mac, making the same 
changes to the the scene graph, with the same stylesheets. So I don’t 
understand the difference I’m seeing.

Scott

> On Mar 15, 2016, at 12:33 PM, David Grieve  wrote:
> 
> Sometimes the layout might introduce nodes into the scenegraph. If these new 
> nodes also need laid out, CSS is applied to those nodes since style can 
> affect layout. I would expect CSS overhead to be very small unless there are 
> many new nodes being added to the scene 
> (https://bugs.openjdk.java.net/browse/JDK-8151756 notwithstanding)
> 
> On 3/15/16 12:14 PM, Scott Palmer wrote:
>> Is there a guideline somewhere that explains how to read the output of the 
>> Pulse Logger?
>> 
>> For example, what do the two times represent in this PULSE line:
>> 
>>  PULSE: 569 [1459ms:270ms]
>> 
>> At first I guessed is that it was PULSE:   [> time>ms:]
>> but that doesn’t seem to hold up.
>> 
>> What does the first (usually negative) number mean in the Layout Pass line?
>> 
>>  T23 (-1563 +1563ms): Layout Pass
>> 
>>  T23 (1 +4ms): Layout Pass
>> 
>> 
>> I’ve noticed that the output has some notable differences between my Windows 
>> machine and my Mac. On the Mac I don’t seem to be getting the same sort of 
>> CSS Pass information.  I get only one “CSS Pass” per pulse and it is almost 
>> always telling me something near 0ms:
>> 
>>  PULSE: 509 [1404ms:286ms]
>>  T23 (-1404 +1404ms): Layout Pass
>>  T23 (0 +1ms): CSS Pass
>>  T23 (1 +6ms): Layout Pass
>>  T23 (7 +4ms): Update bounds
>>  T23 (11 +0ms): Waiting for previous rendering
>>  T23 (11 +0ms): Copy state to render graph
>> 
>> but on Windows I get two CSS Passes, one is usually 0ms, the other makes 
>> more sense (I’m investigating a performance issue on a Scene with >10k 
>> nodes, so some notable amount of CSS time is expected.):
>> 
>>  PULSE: 2578 [423ms:3362ms]
>>  T35 (-423 +423ms): Layout Pass
>>  T35 (0 +0ms): CSS Pass
>>  T35 (0 +0ms): Layout Pass
>>  T35 (0 +2725ms): CSS Pass
>>  T35 (2725 +402ms): Layout Pass
>>  T35 (3128 +25ms): Update bounds
>>  …
>> 
>> This seems a bit strange, as I would think Layout and CSS would not be 
>> platform specific. Both systems are running 8u72.
>> I’m also finding Layout times on the Mac are higher than I expected - maybe 
>> some CSS time has been rolled in to that log line on the Mac?
>> 
>> Regards,
>> 
>> Scott
> 

Re: How do I read the output of the Pulse Logger?

[David Grieve]

Sometimes the layout might introduce nodes into the scenegraph. If these 
new nodes also need laid out, CSS is applied to those nodes since style 
can affect layout. I would expect CSS overhead to be very small unless 
there are many new nodes being added to the scene 
(https://bugs.openjdk.java.net/browse/JDK-8151756 notwithstanding)


On 3/15/16 12:14 PM, Scott Palmer wrote:

Is there a guideline somewhere that explains how to read the output of the 
Pulse Logger?

For example, what do the two times represent in this PULSE line:

PULSE: 569 [1459ms:270ms]

At first I guessed is that it was PULSE:   [ms:]
but that doesn’t seem to hold up.

What does the first (usually negative) number mean in the Layout Pass line?

T23 (-1563 +1563ms): Layout Pass

T23 (1 +4ms): Layout Pass


I’ve noticed that the output has some notable differences between my Windows 
machine and my Mac. On the Mac I don’t seem to be getting the same sort of CSS 
Pass information.  I get only one “CSS Pass” per pulse and it is almost always 
telling me something near 0ms:

PULSE: 509 [1404ms:286ms]
T23 (-1404 +1404ms): Layout Pass
T23 (0 +1ms): CSS Pass
T23 (1 +6ms): Layout Pass
T23 (7 +4ms): Update bounds
T23 (11 +0ms): Waiting for previous rendering
T23 (11 +0ms): Copy state to render graph

but on Windows I get two CSS Passes, one is usually 0ms, the other makes more 
sense (I’m investigating a performance issue on a Scene with >10k nodes, so 
some notable amount of CSS time is expected.):

PULSE: 2578 [423ms:3362ms]
T35 (-423 +423ms): Layout Pass
T35 (0 +0ms): CSS Pass
T35 (0 +0ms): Layout Pass
T35 (0 +2725ms): CSS Pass
T35 (2725 +402ms): Layout Pass
T35 (3128 +25ms): Update bounds
…

This seems a bit strange, as I would think Layout and CSS would not be platform 
specific. Both systems are running 8u72.
I’m also finding Layout times on the Mac are higher than I expected - maybe 
some CSS time has been rolled in to that log line on the Mac?

Regards,

Scott

How do I read the output of the Pulse Logger?

[Scott Palmer]

Is there a guideline somewhere that explains how to read the output of the 
Pulse Logger?

For example, what do the two times represent in this PULSE line:

PULSE: 569 [1459ms:270ms]

At first I guessed is that it was PULSE:   [ms:]
but that doesn’t seem to hold up.

What does the first (usually negative) number mean in the Layout Pass line?

T23 (-1563 +1563ms): Layout Pass

T23 (1 +4ms): Layout Pass


I’ve noticed that the output has some notable differences between my Windows 
machine and my Mac. On the Mac I don’t seem to be getting the same sort of CSS 
Pass information.  I get only one “CSS Pass” per pulse and it is almost always 
telling me something near 0ms:

PULSE: 509 [1404ms:286ms]
T23 (-1404 +1404ms): Layout Pass
T23 (0 +1ms): CSS Pass
T23 (1 +6ms): Layout Pass
T23 (7 +4ms): Update bounds
T23 (11 +0ms): Waiting for previous rendering
T23 (11 +0ms): Copy state to render graph

but on Windows I get two CSS Passes, one is usually 0ms, the other makes more 
sense (I’m investigating a performance issue on a Scene with >10k nodes, so 
some notable amount of CSS time is expected.):

PULSE: 2578 [423ms:3362ms] 
T35 (-423 +423ms): Layout Pass 
T35 (0 +0ms): CSS Pass 
T35 (0 +0ms): Layout Pass 
T35 (0 +2725ms): CSS Pass 
T35 (2725 +402ms): Layout Pass 
T35 (3128 +25ms): Update bounds 
…

This seems a bit strange, as I would think Layout and CSS would not be platform 
specific. Both systems are running 8u72.
I’m also finding Layout times on the Mac are higher than I expected - maybe 
some CSS time has been rolled in to that log line on the Mac?

Regards,

Scott