Ready's distorted sense of time

[Robert Munafo]

Ready consistently underestimates its measurement of elapsed time by a
factor of about 20 to 30. This results in vastly exaggerated "frames
per second" and "mcgs" (millions of cell-generations per second)
benchmark numbers.

For example, in the "Pearson 1993 type Theta" settings that I sent in
the previous message, the timestep is 1 (so there is no difference of
simulation time units to confuse matters).

Using a stopwatch, run for 1 minute 40 seconds (100 seconds). On my
ATi Radeon HD 6750M, at the end of the 100 seconds Ready displays
"Stopped. Timesteps: 24500 (6138 computed frames per second, 402
mcgs)". Since we ran for 100 seconds, this is actually 245 frames per
second or 16.056 mcgs.

I have used my own Gray-Scott program to determine that Ready is
reporting its number of timesteps accurately (in this example, the
amount of activity in the reaction-diffusion pattern agrees with what
my own program shows when it runs the same model for 24500 timesteps.)
It is Ready's measurement of time that is in error. In this example
Ready seems to think that only 4 seconds have elapsed, so it is
overestimating its speed by a factor of 25.

This is happening with every VTI file. In my use of Ready so far, it
seems to be always off by about the same ratio (a factor of about 20
to 30) regardless of my graphics card or the number of cores/threads
in my computer (in the case of using the CPU as the OpenCL device).
However I haven't done a lot of benchmark tests like this to figure
out how much variation there is.

As an aside, this slowness represents the potential for accelerating
Ready by improving the implementation. In our speed comparison tests,
we got performance much much better than this.

--
Robert Munafo -- mrob.com
Follow me at: gplus.to/mrob - fb.com/mrob27 - twitter.com/mrob_27 -
mrob27.wordpress.com - youtube.com/user/mrob143 - rilybot.blogspot.com

[Tim Hutton]

Hi Robert,

You're measuring the actual frames per second but it is showing you
the 'computed frames per second' - the rate at which we could compute
things if there was no rendering going on. Maybe that could be
clearer.

I find that the estimate of computed frames per second (cfps) is
pretty good. Try it again with a timesteps_per_render of 6000 or so.

My results on that file:

As loaded, with timesteps_per_render=100: after 50s I get: Timesteps:
38700 (20000 cfps, 1311 mgcs).
With timesteps_per_render=20000: after 50s I get: Timesteps: 1043200
(23838 cfps, 1562 mgcs).

When you increase the timesteps_per_render to approximately match the
cfps you should get 1 rendered frame per second, more or less. If you
*don't* get this behavior then let me know.

So the cause is that each iteration (just 100 timesteps) is very
small, which means that 95% of the time is spent rendering. That's
fine if you want a fast animation of small changes. (If you want
faster rendering then turn off the displacement_mapped_surface, for
example.) But to process quickly you would want to render less often,
so increase the timesteps_per_render.

Hope this helps clarify things. To avoid confusing others we could
suppress the cfps estimation for short processing blocks (not sure
how). Or we could change the description?

Regards,

Tim

--
Tim Hutton - http://www.sq3.org.uk - http://profiles.google.com/tim.hutton/

[Robert Munafo]

On 10/5/12, Tim Hutton <tim.h...@gmail.com> wrote:
> You're measuring the actual frames per second but it is showing you
> the 'computed frames per second' - the rate at which we could compute
> things if there was no rendering going on. Maybe that could be
> clearer.
>
> I find that the estimate of computed frames per second (cfps) is
> pretty good. Try it again with a timesteps_per_render of 6000 or so.

That's a big improvement! Clearly a lot of time is being spent on the rendering.

Since I like benchmarking, here are some tests to show this effect. In
each test, I have run that same pattern "Pearson 1993 type Theta.vti"
for 20 seconds, with the Timesteps per Render (here labeled "TPR") set
to the indicated number. Following the TPR are the Timesteps and
"frames per second" reported by Ready. Then I show the compute_time,
which is the timesteps divided by Ready's reported frames/sec. Finally
the "inefficiency", which is 20 (the actual elapsed time) divided by
the compute time.

TPR Timesteps: "frames/sec" compute_time inefficiency
100 3700 4617 0.801 24.9
200 7200 7127 1.010 19.8
400 14400 7088 2.032 9.84
800 26400 9865 2.676 7.47
1600 46400 9873 4.700 4.26
3200 75200 9981 7.534 2.65
6400 110400 9970 11.07 1.806
12800 142400 9993 14.25 1.404

In the final test, the screen was updated 11 times (142400 / 12800 =
11.125; this is only one update every 2 seconds). Since 14.25 seconds
were taken computing, that leaves 5.75 seconds for everything else,
which implies that every screen update took about 0.5 seconds! (To its
credit, it really is doing an awful lot in that 0.5 seconds: those two
3D surface plots are pretty impressive if you zoom in so they look
like rolling hills.)

By turning off "show displacement mapped surface" and "show multiple
chemicals", I can make Ready's display much quicker (and closer to
what my own R-D program does). I have reclaimed almost all of that
wasted time. For example:

TPR Timesteps: "frames/sec" compute_time inefficiency
3200 195200 9953 19.61 1.020

> [...] it is showing you

> the 'computed frames per second' - the rate at which we could compute
> things if there was no rendering going on. Maybe that could be
> clearer.

I think that since these numbers look like a benchmark, they need to
tell the truth. The grammatical subtlety of the word "computed" in the
phrase "computed frames per second" does not make up for this. It
should report the frames per second that are actually happening in
reality, not in some hypothetical world in which it is computing but
not displaying.

I would suggest that Ready should measure the total complete actual
elapsed time, rather than just measuring the time that passes while
waiting for an OpenCL call to complete (or whatever it's doing that
makes it measure only the compute time). Then the displayed frames per
second would be indicative of what the user is actually getting.

> When you increase the timesteps_per_render to approximately match the
> cfps you should get 1 rendered frame per second, more or less. If you
> *don't* get this behavior then let me know.

That's pretty close. In the figures above the asymptotic frames per
second is about 10000, and if I set Running Speed to 10000 it does in
fact update the screen a little less than once per second (the
discrepancy is because of the time taken for rendering).

> So the cause is that each iteration (just 100 timesteps) is very
> small, which means that 95% of the time is spent rendering. That's
> fine if you want a fast animation of small changes. (If you want
> faster rendering then turn off the displacement_mapped_surface, for
> example.) But to process quickly you would want to render less often,
> so increase the timesteps_per_render.
>
> Hope this helps clarify things. To avoid confusing others we could
> suppress the cfps estimation for short processing blocks (not sure
> how). Or we could change the description?

[Tim Hutton]

On 6 October 2012 09:17, Robert Munafo <mro...@gmail.com> wrote:
> On 10/5/12, Tim Hutton <tim.h...@gmail.com> wrote:
>> [...] it is showing you
>> the 'computed frames per second' - the rate at which we could compute
>> things if there was no rendering going on. Maybe that could be
>> clearer.
>
> I think that since these numbers look like a benchmark, they need to
> tell the truth. The grammatical subtlety of the word "computed" in the
> phrase "computed frames per second" does not make up for this. It
> should report the frames per second that are actually happening in
> reality, not in some hypothetical world in which it is computing but
> not displaying.
>
> I would suggest that Ready should measure the total complete actual
> elapsed time, rather than just measuring the time that passes while
> waiting for an OpenCL call to complete (or whatever it's doing that
> makes it measure only the compute time). Then the displayed frames per
> second would be indicative of what the user is actually getting.

I've committed a few changes to the status bar. Image attached.

1) It now shows the "timesteps per second", which includes render time
and should match the rate at which the timesteps indicator is going
up, as suggested. I can see your point.

2) It also shows the amount of time spent rendering, in brackets. This
goes down when you increase the timesteps_per_render setting or change
other render settings. Hopefully this figure will make sense to users?
My next task for this release is to display the timesteps_per_render
on the status bar, to help the Run Slower and Run Faster buttons make
more sense.

3) It suppresses the speed information if not enough data has been collected.

4) It updates the speed information less often - previously it was
sometimes too fast to read it.

5) It averages the speed information over 10 renders, to be more
accurate and less jumpy. Sometimes this means having to wait to see
the new speed, not sure if that's a problem.

6) The "mcgs" is no longer shown. Advanced users can compute this if needed.

Let me know of any thoughts on this.

Thanks,

Tim

[Andrew Trevorrow]

Tim:

> I've committed a few changes to the status bar. Image attached.

Looks good to me.

Unrelated suggestion: the Stop button should be red rather than green.

Andrew

[Robert Munafo]

On 10/17/12, Tim Hutton <tim.h...@gmail.com> wrote:
> I've committed a few changes to the status bar. Image attached.
>
> 1) It now shows the "timesteps per second", which includes render time
> and should match the rate at which the timesteps indicator is going
> up, as suggested. I can see your point.
>
> 2) It also shows the amount of time spent rendering, in brackets. This
> goes down when you increase the timesteps_per_render setting or change
> other render settings. Hopefully this figure will make sense to users?
> My next task for this release is to display the timesteps_per_render
> on the status bar, to help the Run Slower and Run Faster buttons make
> more sense.

Thanks Tim -- but I feel I need to apologize.

About a week ago I thought of a way to satisfy my objections but also
keep more of what you had originally ... but I let the thought sit
rather than emailing it out right away.

I realized that your (Tim's) original "frames per second" number is a
benchmark of the computation code, which is really the only part of
the benchmark that we have control over. (For the rendering, we're
pretty much at the mercy of the OpenGL implementation). This is a
useful benchmark that isolates the system's OpenCL performance
specifically, and is also a measure of our (primarily Tim's) work on
the Ready compute code.

Also, as Tim pointed out, this measure of pure computing frames per
second gives the user a really good, quick way to figure out what
setting to use for the "Running Speed..." AKA "timesteps per render"
option: Hit the Tab key, note the "frames per second", then use this
number as the Running Speed, and Ready will then run at one screen
update per second. If you want 2 seconds per update or 2 updates/sec.,
double or halve the number accordingly.

So I was going to suggest replacing the old format:

Timesteps: 100 (3285 computed frames per second, 215 mcgs)

with something like this:

Timesteps: 100 (3.5% computing at 3295 steps/sec; 96.5% rendering)

This is a little different from what you chose to do, because it
preserves your original frames/sec number. If the user cares about the
"actual real-world frames per second" they have the percentages and
can work it out themselves.

As you did, I would have changed "frames per second" to "steps/sec"
because I think it's good not to overuse the word "frames". Ready has
a feature that saves images to a folder every N timesteps, where N is
the "Running Speed" AKA "timesteps per render". If the user is using
these images to make a video, he is likely to think of them as
"frames". That means there are two different concepts of "frame", but
since we're already using the word "timestep", we might as well use
that word everywhere and be consistent. This frees up the word "frame"
to refer to the "N timesteps" that get computed per render.

> 3) It suppresses the speed information if not enough data has been

> collected. [...]

All very good ideas, thanks!

> 6) The "mcgs" is no longer shown. Advanced users can compute this if
> needed.

Yep, I thought the same thing. It's just the computed steps/sec
multiplied by the number of pixels and divided by 1,000,000.