Paint Phase Debugging / Performance

Wed May 9 18:19:12 UTC 2018

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