Re: Paint Phase Debugging / Performance

[Matthew Elliot]

Hey Nir,

In MissionControl the HotMethods section is very interest sometimes; not sure 
if that is where you’re already looking. It might point at the particular part 
of rendering pipeline that is executing too much.

I assume you also captured the JavaFX events and visualised the 
FXApplicationThread and QuantumRenderer threads to see that QuantumRenderer is 
constantly busy. 

I also don’t know how many animations you have but we also introduced a single 
central animation which modified properties triggering other components to 
redraw. This meant we only had 1 animation instead of dozens or hundreds. Not 
sure if this makes such a big difference to painting. 

Maybe also worth trying is in the IDE (I.e. IntelliJ) to Instrument the code 
with the debugger by evaluate and logging timestamps in the code. If you look 
at breakpoint properties you can put inside ‘Evaluate and log’ block 
System.currentTimeMillis(). Not sure how much it’ll drag performance back but 
maybe on prism frames per second = 1 and many breakpoints in the painting 
pipeline you can at least find where it spends all the time. 

Beyond that I’d be out of ideas. 
Matt

Sent from my phone.

> On 9/05/2018, at 1:15 AM, Nir Lisker  wrote:
> 
> Hi Matthew,
> 
> This is a typical pulse, which indeed cases the effect of low FPS, and that's 
> what I'm trying to solve.
> 
> * Cache hints are ignored for 3D (but I tried anyway).
> * -Dprism.showdirty and printrendergraph also don't work for 3D scenes 
> (though I can get an approximation with a 2D scene).
> * There are no effects.
> 
> I'm working with Mission Control already, most of the instances in the GC 
> class histogram are related to animation classes: 
> InterpolationInterval$TangentDoubleInterpolationInterval and 
> NumberTangentInterpolator.
> 
> Looks like all all the discussed difficulties with diagnostics are enhanced 
> when it comes to 3D. Will have to dig deep on this one.
> 
> Thanks,
> Nir
> 
>> On Mon, May 7, 2018 at 9:07 PM, Matthew Elliot 
>>  wrote:
>> Hey Nir,
>> 
>> I’m not sure if I can offer much support as I haven’t been into the 3D world 
>> but just to clarify, is it one pulse after another with long wait, paint 
>> phases? From what I’ve seen personally if you have painting of 100+ 
>> milliseconds on every pulse you will be in big trouble / laggy as. 
>> 
>> On a one-off pulse like building a scene the first time I would say it is 
>> fine but regular paints that are longer are going to cause issues from my 
>> experience.
>> 
>> Did you try profiling with mission controller to look at what garbage is 
>> being created / what hot methods there? Maybe it points you in a better 
>> direction / at least rule out your own code. 
>> 
>> With animations I guess you set cache hints already?
>> 
>> Make sure you don’t have any effects on the animation as well, a Gaussian 
>> blur blend/drop shadow on an animation killed it for me. 
>> You can also try -Dprism.disableEffects= true to rule it out. 
>> You can also enable the prism option to show what is being painted on each 
>> pulse as an overlay. -Dprism.showdirty and there is another I forget to show 
>> how many times it was painted. (Not that your whole scene is painted when 
>> you expect a small part of it)
>> 
>> Or some trial and error with the prism flags here to try narrow it down - 
>> Just open PrismSettings.java in your IDE or web browser. 
>> 
>> Code explains them better than most posts I’ve seen.
>> 
>> Good luck. 
>> Matt
>> 
>> Sent from my phone.
>> 
>>> On 7/05/2018, at 2:36 PM, Nir Lisker  wrote:
>>> 
>>> Hi,
>>> 
>>> I'm having a performance issue myself. I'm using animations on 3D models 
>>> (in a 3D subscene) and when there are "too many" models the QuantumRenderer 
>>> thread is running 100% of the time and utilizing 20-25% of the CPU, though 
>>> the OS reports that overall all cores are at ~40%. The application is using 
>>> the d3d pipeline.
>>> 
>>> A typical pulse is
>>> 
>>> PULSE: 4078 [112ms:225ms]
>>> T15 (11 +0ms): CSS Pass
>>> T15 (11 +0ms): Layout Pass
>>> T15 (12 +0ms): Update bounds
>>> T15 (12 +95ms): Waiting for previous rendering
>>> T15 (108 +0ms): Copy state to render graph
>>> T12 (109 +115ms): Painting
>>> T12 (224 +0ms): Presenting
>>> Counters:
>>> Nodes rendered: 651
>>> Nodes visited during render: 651
>>> 
>>> Thread dumps show that QuantumRenderer is busy with tasks inside
>>> 
>>> at 
>>> com.sun.prism.impl.BaseMesh.buildPTGeometry(javafx.graphics@10-internal/BaseMesh.java:584)
>>> at 
>>> com.sun.prism.impl.BaseMesh.buildGeometry(javafx.graphics@10-internal/BaseMesh.java:516)
>>> at 
>>> com.sun.javafx.sg.prism.NGTriangleMesh.validate(javafx.graphics@10-internal/NGTriangleMesh.java:75)
>>> at 
>>> com.sun.javafx.sg.prism.NGShape3D.renderMeshView(javafx.graphics@10-internal/NGShape3D.java:84)
>>> at 
>>> 

Re: Paint Phase Debugging / Performance

[Nir Lisker]

Hi Matthew,

This is a typical pulse, which indeed cases the effect of low FPS, and
that's what I'm trying to solve.

* Cache hints are ignored for 3D (but I tried anyway).
* -Dprism.showdirty and printrendergraph also don't work for 3D scenes
(though I can get an approximation with a 2D scene).
* There are no effects.

I'm working with Mission Control already, most of the instances in the GC
class histogram are related to animation
classes: InterpolationInterval$TangentDoubleInterpolationInterval
and NumberTangentInterpolator.

Looks like all all the discussed difficulties with diagnostics are enhanced
when it comes to 3D. Will have to dig deep on this one.

Thanks,
Nir

On Mon, May 7, 2018 at 9:07 PM, Matthew Elliot <
matthew.james.ell...@gmail.com> wrote:

> Hey Nir,
>
> I’m not sure if I can offer much support as I haven’t been into the 3D
> world but just to clarify, is it one pulse after another with long wait,
> paint phases? From what I’ve seen personally if you have painting of 100+
> milliseconds on every pulse you will be in big trouble / laggy as.
>
> On a one-off pulse like building a scene the first time I would say it is
> fine but regular paints that are longer are going to cause issues from my
> experience.
>
> Did you try profiling with mission controller to look at what garbage is
> being created / what hot methods there? Maybe it points you in a better
> direction / at least rule out your own code.
>
> With animations I guess you set cache hints already?
>
> Make sure you don’t have any effects on the animation as well, a Gaussian
> blur blend/drop shadow on an animation killed it for me.
> You can also try -Dprism.disableEffects= true to rule it out.
> You can also enable the prism option to show what is being painted on each
> pulse as an overlay. -Dprism.showdirty and there is another I forget to
> show how many times it was painted. (Not that your whole scene is painted
> when you expect a small part of it)
>
> Or some trial and error with the prism flags here to try narrow it down -
> Just open PrismSettings.java in your IDE or web browser.
>
> Code explains them better than most posts I’ve seen.
>
> Good luck.
> Matt
>
> Sent from my phone.
>
> On 7/05/2018, at 2:36 PM, Nir Lisker  wrote:
>
> Hi,
>
> I'm having a performance issue myself. I'm using animations on 3D models
> (in a 3D subscene) and when there are "too many" models the QuantumRenderer
> thread is running 100% of the time and utilizing 20-25% of the CPU, though
> the OS reports that overall all cores are at ~40%. The application is using
> the d3d pipeline.
>
> A typical pulse is
>
> PULSE: 4078 [112ms:225ms]
> T15 (11 +0ms): CSS Pass
> T15 (11 +0ms): Layout Pass
> T15 (12 +0ms): Update bounds
> T15 (12 +95ms): Waiting for previous rendering
> T15 (108 +0ms): Copy state to render graph
> T12 (109 +115ms): Painting
> T12 (224 +0ms): Presenting
> Counters:
> Nodes rendered: 651
> Nodes visited during render: 651
>
> Thread dumps show that QuantumRenderer is busy with tasks inside
>
> at com.sun.prism.impl.BaseMesh.buildPTGeometry(javafx.
> graphics@10-internal/BaseMesh.java:584)
> at com.sun.prism.impl.BaseMesh.buildGeometry(javafx.graphics@
> 10-internal/BaseMesh.java:516)
> at com.sun.javafx.sg.prism.NGTriangleMesh.validate(
> javafx.graphics@10-internal/NGTriangleMesh.java:75)
> at com.sun.javafx.sg.prism.NGShape3D.renderMeshView(
> javafx.graphics@10-internal/NGShape3D.java:84)
> at com.sun.javafx.sg.prism.NGShape3D.renderContent(
> javafx.graphics@10-internal/NGShape3D.java:201)
> at com.sun.javafx.sg.prism.NGNode.doRender(javafx.
> graphics@10-internal/NGNode.java:2072)
> at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@
> 10-internal/NGNode.java:1964)
> at com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.
> graphics@10-internal/NGGroup.java:270)
> at com.sun.javafx.sg.prism.NGNode.doRender(javafx.
> graphics@10-internal/NGNode.java:2072)
> at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@
> 10-internal/NGNode.java:1964)
> at com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.
> graphics@10-internal/NGGroup.java:270)
> at com.sun.javafx.sg.prism.NGNode.doRender(javafx.
> graphics@10-internal/NGNode.java:2072)
> at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@
> 10-internal/NGNode.java:1964)
> at com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.
> graphics@10-internal/NGGroup.java:270)
> at com.sun.javafx.sg.prism.NGNode.renderCached(javafx.
> graphics@10-internal/NGNode.java:2379)
> at com.sun.javafx.sg.prism.NGNode.doRender(javafx.
> graphics@10-internal/NGNode.java:2063)
> at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@
> 10-internal/NGNode.java:1964)
> at com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.
> graphics@10-internal/NGGroup.java:270)
> at 

Re: Paint Phase Debugging / Performance

[Matthew Elliot]

Hey Nir,

I’m not sure if I can offer much support as I haven’t been into the 3D world 
but just to clarify, is it one pulse after another with long wait, paint 
phases? From what I’ve seen personally if you have painting of 100+ 
milliseconds on every pulse you will be in big trouble / laggy as. 

On a one-off pulse like building a scene the first time I would say it is fine 
but regular paints that are longer are going to cause issues from my experience.

Did you try profiling with mission controller to look at what garbage is being 
created / what hot methods there? Maybe it points you in a better direction / 
at least rule out your own code. 

With animations I guess you set cache hints already?

Make sure you don’t have any effects on the animation as well, a Gaussian blur 
blend/drop shadow on an animation killed it for me. 
You can also try -Dprism.disableEffects= true to rule it out. 
You can also enable the prism option to show what is being painted on each 
pulse as an overlay. -Dprism.showdirty and there is another I forget to show 
how many times it was painted. (Not that your whole scene is painted when you 
expect a small part of it)

Or some trial and error with the prism flags here to try narrow it down - Just 
open PrismSettings.java in your IDE or web browser. 

Code explains them better than most posts I’ve seen.

Good luck. 
Matt

Sent from my phone.

> On 7/05/2018, at 2:36 PM, Nir Lisker  wrote:
> 
> Hi,
> 
> I'm having a performance issue myself. I'm using animations on 3D models (in 
> a 3D subscene) and when there are "too many" models the QuantumRenderer 
> thread is running 100% of the time and utilizing 20-25% of the CPU, though 
> the OS reports that overall all cores are at ~40%. The application is using 
> the d3d pipeline.
> 
> A typical pulse is
> 
> PULSE: 4078 [112ms:225ms]
> T15 (11 +0ms): CSS Pass
> T15 (11 +0ms): Layout Pass
> T15 (12 +0ms): Update bounds
> T15 (12 +95ms): Waiting for previous rendering
> T15 (108 +0ms): Copy state to render graph
> T12 (109 +115ms): Painting
> T12 (224 +0ms): Presenting
> Counters:
>   Nodes rendered: 651
>   Nodes visited during render: 651
> 
> Thread dumps show that QuantumRenderer is busy with tasks inside
> 
> at 
> com.sun.prism.impl.BaseMesh.buildPTGeometry(javafx.graphics@10-internal/BaseMesh.java:584)
> at 
> com.sun.prism.impl.BaseMesh.buildGeometry(javafx.graphics@10-internal/BaseMesh.java:516)
> at 
> com.sun.javafx.sg.prism.NGTriangleMesh.validate(javafx.graphics@10-internal/NGTriangleMesh.java:75)
> at 
> com.sun.javafx.sg.prism.NGShape3D.renderMeshView(javafx.graphics@10-internal/NGShape3D.java:84)
> at 
> com.sun.javafx.sg.prism.NGShape3D.renderContent(javafx.graphics@10-internal/NGShape3D.java:201)
> at 
> com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal/NGNode.java:2072)
> at 
> com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal/NGNode.java:1964)
> at 
> com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal/NGGroup.java:270)
> at 
> com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal/NGNode.java:2072)
> at 
> com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal/NGNode.java:1964)
> at 
> com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal/NGGroup.java:270)
> at 
> com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal/NGNode.java:2072)
> at 
> com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal/NGNode.java:1964)
> at 
> com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal/NGGroup.java:270)
> at 
> com.sun.javafx.sg.prism.NGNode.renderCached(javafx.graphics@10-internal/NGNode.java:2379)
> at 
> com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal/NGNode.java:2063)
> at 
> com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal/NGNode.java:1964)
> at 
> com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal/NGGroup.java:270)
> at 
> com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal/NGNode.java:2072)
> at 
> com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal/NGNode.java:1964)
> at 
> com.sun.javafx.tk.quantum.ViewPainter.doPaint(javafx.graphics@10-internal/ViewPainter.java:479)
> at 
> com.sun.javafx.tk.quantum.ViewPainter.paintImpl(javafx.graphics@10-internal/ViewPainter.java:328)
> at 
> com.sun.javafx.tk.quantum.PresentingPainter.run(javafx.graphics@10-internal/PresentingPainter.java:91)
> at 
> java.util.concurrent.Executors$RunnableAdapter.call(java.base@10-internal/Executors.java:514)
> at 
> java.util.concurrent.FutureTask.runAndReset(java.base@10-internal/FutureTask.java:305)
> at 
> 

Re: Paint Phase Debugging / Performance

[Nir Lisker]

Hi,

I'm having a performance issue myself. I'm using animations on 3D models
(in a 3D subscene) and when there are "too many" models the QuantumRenderer
thread is running 100% of the time and utilizing 20-25% of the CPU, though
the OS reports that overall all cores are at ~40%. The application is using
the d3d pipeline.

A typical pulse is

PULSE: 4078 [112ms:225ms]
T15 (11 +0ms): CSS Pass
T15 (11 +0ms): Layout Pass
T15 (12 +0ms): Update bounds
T15 (12 +95ms): Waiting for previous rendering
T15 (108 +0ms): Copy state to render graph
T12 (109 +115ms): Painting
T12 (224 +0ms): Presenting
Counters:
Nodes rendered: 651
Nodes visited during render: 651

Thread dumps show that QuantumRenderer is busy with tasks inside

at
com.sun.prism.impl.BaseMesh.buildPTGeometry(javafx.graphics@10-internal
/BaseMesh.java:584)
at
com.sun.prism.impl.BaseMesh.buildGeometry(javafx.graphics@10-internal
/BaseMesh.java:516)
at
com.sun.javafx.sg.prism.NGTriangleMesh.validate(javafx.graphics@10-internal
/NGTriangleMesh.java:75)
at
com.sun.javafx.sg.prism.NGShape3D.renderMeshView(javafx.graphics@10-internal
/NGShape3D.java:84)
at
com.sun.javafx.sg.prism.NGShape3D.renderContent(javafx.graphics@10-internal
/NGShape3D.java:201)
at
com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal
/NGNode.java:2072)
at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal
/NGNode.java:1964)
at
com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal
/NGGroup.java:270)
at
com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal
/NGNode.java:2072)
at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal
/NGNode.java:1964)
at
com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal
/NGGroup.java:270)
at
com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal
/NGNode.java:2072)
at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal
/NGNode.java:1964)
at
com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal
/NGGroup.java:270)
at
com.sun.javafx.sg.prism.NGNode.renderCached(javafx.graphics@10-internal
/NGNode.java:2379)
at
com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal
/NGNode.java:2063)
at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal
/NGNode.java:1964)
at
com.sun.javafx.sg.prism.NGGroup.renderContent(javafx.graphics@10-internal
/NGGroup.java:270)
at
com.sun.javafx.sg.prism.NGNode.doRender(javafx.graphics@10-internal
/NGNode.java:2072)
at com.sun.javafx.sg.prism.NGNode.render(javafx.graphics@10-internal
/NGNode.java:1964)
at
com.sun.javafx.tk.quantum.ViewPainter.doPaint(javafx.graphics@10-internal
/ViewPainter.java:479)
at
com.sun.javafx.tk.quantum.ViewPainter.paintImpl(javafx.graphics@10-internal
/ViewPainter.java:328)
at
com.sun.javafx.tk.quantum.PresentingPainter.run(javafx.graphics@10-internal
/PresentingPainter.java:91)
at
java.util.concurrent.Executors$RunnableAdapter.call(java.base@10-internal
/Executors.java:514)
at java.util.concurrent.FutureTask.runAndReset(java.base@10-internal
/FutureTask.java:305)
at com.sun.javafx.tk.RenderJob.run(javafx.graphics@10-internal
/RenderJob.java:58)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@10-internal
/ThreadPoolExecutor.java:1135)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@10-internal
/ThreadPoolExecutor.java:635)
at
com.sun.javafx.tk.quantum.QuantumRenderer$PipelineRunnable.run(javafx.graphics@10-internal
/QuantumRenderer.java:125)
at java.lang.Thread.run(java.base@10-internal/Thread.java:844)

Does anyone have an idea on how to continue?

Thanks,
Nir


On Fri, May 4, 2018 at 10:30 AM, Matthew Elliot <
matthew.james.ell...@gmail.com> wrote:

> Hi Pedro,
>
> The first link I have read through many times, it is very useful for ideas
> but doesn't really flesh out or go into much detail on each topic. It also
> comments a few times on the problems we've encountered, 'what costs what'
> is difficult to understand / measure.
>
> The second link I hadn't found my way to and is definitely interesting to
> understand more about how things are working internally - thanks.
>
> Regards,
> Matt
>
>
> On 3 May 2018 at 19:17, Pedro Duque Vieira 
> wrote:
>
> > Hi Matthew,
> >
> > On the topic of documents with indications for improving performance.
> >
> > Don't know if you already found it, but there is a draft here (to which
> > I've made a small contribution):
> > https://wiki.openjdk.java.net/display/OpenJFX/Performance+
> Tips+and+Tricks
> >
> > A bit old though...
> >
> > And here:
> >
> > https://wiki.openjdk.java.net/display/OpenJFX/Performance+Ideas
> >
> >
> > --
> > Pedro Duque Vieira
> >
>

Re: Paint Phase Debugging / Performance

[Matthew Elliot]

Hi Pedro,

The first link I have read through many times, it is very useful for ideas
but doesn't really flesh out or go into much detail on each topic. It also
comments a few times on the problems we've encountered, 'what costs what'
is difficult to understand / measure.

The second link I hadn't found my way to and is definitely interesting to
understand more about how things are working internally - thanks.

Regards,
Matt


On 3 May 2018 at 19:17, Pedro Duque Vieira 
wrote:

> Hi Matthew,
>
> On the topic of documents with indications for improving performance.
>
> Don't know if you already found it, but there is a draft here (to which
> I've made a small contribution):
> https://wiki.openjdk.java.net/display/OpenJFX/Performance+Tips+and+Tricks
>
> A bit old though...
>
> And here:
>
> https://wiki.openjdk.java.net/display/OpenJFX/Performance+Ideas
>
>
> --
> Pedro Duque Vieira
>

Re: Paint Phase Debugging / Performance

[Pedro Duque Vieira]

Hi Matthew,

On the topic of documents with indications for improving performance.

Don't know if you already found it, but there is a draft here (to which
I've made a small contribution):
https://wiki.openjdk.java.net/display/OpenJFX/Performance+Tips+and+Tricks

A bit old though...

And here:

https://wiki.openjdk.java.net/display/OpenJFX/Performance+Ideas


-- 
Pedro Duque Vieira

Re: Paint Phase Debugging / Performance

[Matthew Elliot]

Hey Johan, thanks for the detailed answer.

Perhaps a bit more context as well... from our experience it seems about
10-12% of the setups we hit fall back to Software because of various issues
or predominantly or 'sadly' virtualisation like Citrix so we have to be
sure in SW mode things run optimally. It isn't necessarily a bad thing to
optimise for the lowest common denominator if you want a fast application
everywhere.
Given this learning I'm now looking to how ensure we somehow 'box' what a
minimum performance looks like and ensure with every change we don't really
get away from that + communicate costs clearly with the UX team.
That way when our developers step on land mines we detect the missing limbs
the same day.

That's the direction I'm currently thinking about and of course I can't be
the only one (hence the post).

I don't like it when people say that "JavaFX is slow" because if everything
is done right, JavaFX can be extremely fast.
But I also realise that it is very easy to make things very slow in JavaFX,
and in case "performance" is slow, it is important to pinpoint the problem
as easy as possible. And that is often not trivial, so the easier it
becomes to detect problems, the more developers will like JavaFX.

>>> Agree that JavaFX can be fast and given we have to support thousands of
setups that we have no control over I'm quite content with how JavaFX is
performing in the wild.
It definitely has a few performance traps that aren't so easy notice from
the high level API, css, effects, etc.
And while blocking the JavaFX thread happens the most frequent it also is
simple to explain to any reasonable developer and easy to troubleshoot as
it is something you influence directly, whereas css pass, layout or paint
are much more indirect and tricky.
An effect on top on an animation for example was very tricky to find. In
this case the framework should even perhaps refuse to do it in software
mode... :)

To a few other points:

The options in PrismSettings.java (e.g. prism.trace,
prism.printrendergraph, prism.showdirty) and in QuantumToolit
(quantum.debug) can be helpful as well.

>>> Are you aware of any write up on the internet about understanding the
output? I mean I had to read the code and use breakpoints for the prism
logger for 'slow background path for null' to understand but it would be
nice if someone has already written about these topics? There is also no
book on JavaFX perf right?
On the other side and regarding analysing issues I think there is also a
wealth of tooling / logging that is useful but it took me a while to work
my way into the performance investigation as the information is scattered
and or incomplete (at least with my googlefu).

It would be great to have tools that auto-detect this. Detecting slow
render phases is already done, but linking to the root cause is of course
much harder.
I don't think that interrupting the paint phase is a good thing. If that
takes 200-300 ms, it is very likely it will take 200-300ms in the next
cycle.

>>> Auto-detection is a hard science, hence why as a developer I wouldn't
mind setting explicitly for my CI perf builds, break if condition A happens
so I can review what changed recently.
>>> At 200-300 ms the application became unusable essentially in our case
as every scheduled pulse was either waiting or painting. I will create
something to also detect this going forward to avoid a repeat (question
just is what).
>>> Of course now I will redirect stdErr and parse it on the fly and/or go
in via reflection but it would be nice if prism would allow to set short
cuts or at least spit additional ERROR or WARNs.

It might be an option though to dynamically throttle the pulse frequency
(which can now only be changed at startup with javafx.animation.pulse) in
case slow rendering is detected.
>>> Does this matter much as the pulses anyway just get skipped, or? In
this case the fact that the animation is still trying to run when the pulse
is almost stalled doesn't make sense and circuit-breaking it would be
perhaps 'intelligent' framework behaviour.

When things are slow in the paint phase, the information about how many
Nodes are visited and rendered, and how many are cached is very useful. I
have a local debug version where I keep track of how many times a Node is
rendered from cache versus how often the cache is invalid and needs to be
recomputed (which is extremely expensive). It this was somehow automated,
it could improve performance. It is similar to what hotspot C1/C2 is doing
for code: it is expensive to compile all code at runtime, but when it turns
out methods are often used, they are compiled. Similar, if the rendering
pipeline detects that a node would remain cache-valid for most of the time,
it might automatically set that node.setCache(true). But that's not a
trivial thing to implement.
>>> I still can't 100% work out what exactly one should cache from what
I've googled. I mean, I only need to cache it if it will be redrawn right,

Re: Paint Phase Debugging / Performance

[Johan Vos]

Hi Matthew,

I agree this is a very important question.

I don't like it when people say that "JavaFX is slow" because if everything
is done right, JavaFX can be extremely fast.
But I also realise that it is very easy to make things very slow in JavaFX,
and in case "performance" is slow, it is important to pinpoint the problem
as easy as possible. And that is often not trivial, so the easier it
becomes to detect problems, the more developers will like JavaFX.

I typically start with setting prism.verbose and javafx.pulseLogger to
true, as you first need to know in which phase the problem is (e.g. layout
or render phase). If you see the problem is in the render phase, you have
to look at completely different things.
Note that in most cases I've seen with bad performance, the problem was not
in the rendering, but simply due to too much happening on the JavaFX
application thread, preventing it to start doing the rendering.
Those things are typically easily detected by generating thread dumps or
using simple profilers to find out what the JavaFX thread is typically
doing. If you see bad performance but in 90% of the thread dump there is no
trace of rendering, you know where to look.

When things are slow in the paint phase, the information about how many
Nodes are visited and rendered, and how many are cached is very useful. I
have a local debug version where I keep track of how many times a Node is
rendered from cache versus how often the cache is invalid and needs to be
recomputed (which is extremely expensive). It this was somehow automated,
it could improve performance. It is similar to what hotspot C1/C2 is doing
for code: it is expensive to compile all code at runtime, but when it turns
out methods are often used, they are compiled. Similar, if the rendering
pipeline detects that a node would remain cache-valid for most of the time,
it might automatically set that node.setCache(true). But that's not a
trivial thing to implement.

The options in PrismSettings.java (e.g. prism.trace,
prism.printrendergraph, prism.showdirty) and in QuantumToolit
(quantum.debug) can be helpful as well.

When there are no clear indications (e.g. not too many nodes, no invalid
caches), I go for profiling, working bottom-up. I have the JavaFX source
code always at hand when doing this, in order to see what exactly is
happening.
There are some patterns, e.g. on Android I know that lots of time spent in
System.arraycopy is an indication about lots of slow CSS processing (Bitset
operations, if you follow the profiling information bottom-up)

It would be great to have tools that auto-detect this. Detecting slow
render phases is already done, but linking to the root cause is of course
much harder.

I don't think that interrupting the paint phase is a good thing. If that
takes 200-300 ms, it is very likely it will take 200-300ms in the next
cycle.

It might be an option though to dynamically throttle the pulse frequency
(which can now only be changed at startup with javafx.animation.pulse) in
case slow rendering is detected.

- Johan


On Tue, May 1, 2018 at 8:17 PM Matthew Elliot <
matthew.james.ell...@gmail.com> wrote:

> Hi all,
>
> The last few days I was troubleshooting a new performance issue that showed
> up in our PROD application where customers had fallen back to the SW
> rendering pipeline. It severely affected the application where CPU
> frequency was under 3 GHz with hover lags of a few seconds in the worst
> cases. With thousands of potential HW/SW combinations in the wild it took
> quite a while to even identify it really was an issue in our application
> and not the usual noise of some silly set up. All this got me thinking...
>
> ... what was visible was long paint passes, and long waiting on previous
> render but narrowing this down to exactly what was going on took a lot of
> manual inspection of the rendering pipeline code / debugging and somewhat
> by chance I stumbled over the -Dprism.disableEffects flag which after much
> more pain helped me narrow down the issue.
>
> The root cause turned out to be an -fx-effect (blend, inner shadow) on an
> animated node that was set from the code by an unknowing developer.
>
> While there are tools like mission controller for visualising the pulse and
> phases it can be difficult to identify for example what is going wrong
> inside of the painting phase and it is difficult to control that nothing
> bad happens when many developers can make changes to the code and reviews
> will never catch everything... I'm therefore thinking about ways to run
> rendering tests in continuous integration that would fail fast if the SW
> rendering pipeline would get overloaded.
> I had a look at PulseListener where I could see pulse times but I'd like to
> go more detailed and actually like the information tracked in the internals
> of PulseLogger (PulseData) without doing any nasty tricks.
>
> I thought maybe somebody has already thought about this problem before and
> maybe there is even