[Paraview] How to interpret timer log

Wed Oct 7 09:32:18 EDT 2009

The only reason why the two systems should give different results is if they are loading different data or the settings do not match up, which you claim is not the case.  If you want to ensure that the settings are the same, you can launch ParaView with the -dr flag, which will ignore your settings file and use all the default settings.

The decision for using parallel rendering or to transfer data to the client is made in vtkSMMultiProcessRenderView::GetCompositingDecision(), which is called on the client.  If you really want to find out what is going on, you can set a breakpoint there and see what the decision is and how ParaView came about it.

-Ken

On 10/7/09 4:51 AM, "chew ping" <lcp81um at msn.com> wrote:

Hi all,

thanks for the reply below.

my friend and i each run parallel rendering using our own notebook as client, but we use the same data, same servers and same version of ParaView, CMake, QT, MPI. We use same settings and did the same thing, however our timer log results are a little bit different.

My timer log result
----------------------------------------------------------------------
Local Process
--- Disable display lists.
--- Disable triangle strips.
Still Render, 0.043315 seconds
Still Render, 0.021299 seconds
Still Render, 0.024769 seconds
Still Render, 0.02782 seconds
Still Render, 10.7477 seconds
Execute vtkMPIMoveData id: 462, 3.73372 seconds

Server, Process 0
Execute vtkFileSeriesReader id: 182, 0.641624 seconds
Execute vtkPVGeometryFilter id: 248, 0.005231 seconds
Execute vtkPVCacheKeeper id: 459, 6.9e-05 seconds
Execute vtkMPIMoveData id: 462, 3.3546 seconds
Dataserver gathering to 0, 0.831371 seconds
Dataserver sending to client, 2.5226 seconds
Execute vtkOrderedCompositeDistributor , 0.000142 seconds

Server, Process 1
Execute vtkFileSeriesReader id: 182, 0.000345 seconds
Execute vtkPVGeometryFilter id: 248, 0.005231 seconds
Execute vtkPVCacheKeeper id: 459, 5.7e-05 seconds
Execute vtkMPIMoveData id: 462, 0.14266 seconds
Dataserver gathering to 0, 0.142351 seconds
Execute vtkOrderedCompositeDistributor , 9.8e-05 seconds

Server, Process 2
Execute vtkFileSeriesReader id: 182, 0.000325 seconds
Execute vtkPVGeometryFilter id: 248, 0.004975 seconds
Execute vtkPVCacheKeeper id: 459, 6.3e-05 seconds
Execute vtkMPIMoveData id: 462, 0.244045 seconds
Dataserver gathering to 0, 0.243799 seconds
Execute vtkOrderedCompositeDistributor , 9.7e-05 seconds

Server, Process 3
Execute vtkFileSeriesReader id: 182, 0.000408 seconds
Execute vtkPVGeometryFilter id: 248, 0.00521 seconds
Execute vtkPVCacheKeeper id: 459, 5.6e-05 seconds
Execute vtkMPIMoveData id: 462, 0.192467 seconds
Dataserver gathering to 0, 0.192195 seconds
Execute vtkOrderedCompositeDistributor , 0.000113 seconds

-----------------------------------------------------------------------

My friend's timer log result

-----------------------------------------------------------------------
Local Process
Still Render, 3.98618 seconds

Server, Process 0
Execute vtkFileSeriesReader id: 2927, 1.18069 seconds
Execute vtkPVGeometryFilter id: 2992, 0.041116 seconds
Execute vtkPVCacheKeeper id: 3203, 6.7e-05 seconds
Execute vtkMPIMoveData id: 3206, 0.000195 seconds
Execute vtkOrderedCompositeDistributor , 0.000138 seconds
Execute vtkPolyDataMapper id: 2998, 0.000101 seconds
Execute vtkPolyDataMapper id: 2853, 5.5e-05 seconds
Execute vtkPolyDataMapper id: 2998, 4.5e-05 seconds

Server, Process 1
Execute vtkFileSeriesReader id: 2927, 0.000275 seconds
Execute vtkPVGeometryFilter id: 2992, 0.019066 seconds
Execute vtkPVCacheKeeper id: 3203, 6.4e-05 seconds
Execute vtkMPIMoveData id: 3206, 0.000123 seconds
Execute vtkOrderedCompositeDistributor , 8.9e-05 seconds
Execute vtkPolyDataMapper id: 2998, 7.3e-05 seconds
Execute vtkPolyDataMapper id: 2853, 5.5e-05 seconds
Execute vtkPolyDataMapper id: 2998, 4.8e-05 seconds

Server, Process 2
Execute vtkFileSeriesReader id: 2927, 0.000303 seconds
Execute vtkPVGeometryFilter id: 2992, 0.02033 seconds
Execute vtkPVCacheKeeper id: 3203, 5.3e-05 seconds
Execute vtkMPIMoveData id: 3206, 0.000158 seconds
Execute vtkOrderedCompositeDistributor , 9.6e-05 seconds
Execute vtkPolyDataMapper id: 2998, 8.9e-05 seconds
Execute vtkPolyDataMapper id: 2853, 5.2e-05 seconds
Execute vtkPolyDataMapper id: 2998, 4.7e-05 seconds

Server, Process 3
Execute vtkFileSeriesReader id: 2927, 0.000311 seconds
Execute vtkPVGeometryFilter id: 2992, 0.02033 seconds
Execute vtkPVCacheKeeper id: 3203, 6e-05 seconds
Execute vtkMPIMoveData id: 3206, 0.000117 seconds
Execute vtkOrderedCompositeDistributor , 9e-05 seconds
Execute vtkPolyDataMapper id: 2998, 8.3e-05 seconds
Execute vtkPolyDataMapper id: 2853, 5.2e-05 seconds
Execute vtkPolyDataMapper id: 2998, 4.7e-05 seconds

--------------------------------------------------------------------------

My question are:

my local process has Execute vtkMPIMoveData, but my friend's doesn't, why?
my process 0 has Dataserver gathering to 0, Dataserver sending to client, but my friend's doesn't, why?
my process 1,2,3 has Dataserver gathering to 0, but my friend's doesn't, why?

Appreciate your reply, thanks!

regards,
chew ping

________________________________
From: dave.demarle at kitware.com
Date: Wed, 30 Sep 2009 09:27:32 -0400
Subject: Re: [Paraview] How to interpret timer log
To: lcp81um at msn.com
CC: kmorel at sandia.gov; paraview at paraview.org; kitware at kitware.com

I counted more than one question (six in fact) in that last email. :)
does these mean that, at the client's end, it took 3.029 seconds to renders the geometry send back from process 0?

I believe the 3.029 seconds includes the transfer time, but I may be incorrect on that. Someone please correct me if I am wrong.

what does still render means?

While you drag the mouse and move the camera paraview does interactive renders. Iteractive renders will (depending on data and the preference settings) use subsampled geometry and subsampled images. Once you release the mouse, ParaView does a still render at full resolution.

how about the third line? after still render, why does the MPI need to move data?

See answer to question 1, the MPI time (and processing) is being counted as part of the rendering. Since it is "part of" the rendering, it shows up after in the log (even if it happened first).

which data?

Geometry (the surface of whatever your data is).

to where?