Page MenuHome

Cycles: add debug logging for timing scene update
ClosedPublic

Authored by Kévin Dietrich (kevindietrich) on Aug 17 2020, 4:54 PM.

Details

Summary

This is a quick version to to get initial numbers, not intended to be committed
as is but can be used to analyze existing bottlenecks. The output is a bit of a
mess mixed with everything else.

A nicer version of this could extend the mechanism of render/stats.h, with the
ability to print a summary with better formatting and indentation.

Ref T79174

Diff Detail

Repository
rB Blender

Event Timeline

Brecht Van Lommel (brecht) requested review of this revision.Aug 17 2020, 4:54 PM
Brecht Van Lommel (brecht) planned changes to this revision.Aug 17 2020, 4:54 PM

I quickly modified this patch by extending render/stats.h, it's a bit rough on the edges, but has a nicer output. It would also need a way enable/disable the stats collection and report output.

Here's an example output from classroom.blend:

Scene:
    Total time: 2.376954s
        device_update                            2.376954s
Geometry:
    Total time: 0.171905s
        device_update (build scene BVH)          0.106884s
        device_update (normals)                  0.025609s
        device_update (copy meshes to device)    0.016638s
        device_update (build object BVHs)        0.014360s
        device_update (attributes)               0.008285s
        device_update (compute bounds)           0.000065s
        device_update (displacement)             0.000035s
        device_update_preprocess                 0.000029s
Light:
    Total time: 0.007216s
        device_update                            0.007216s
Object:
    Total time: 0.004839s
        device_update (copy objects to device)   0.003567s
        device_update (apply static transforms)  0.001214s
        device_update_flags                      0.000045s
        device_update (assign index)             0.000013s
Image:
    Total time: 1.689158s
        device_update                            1.689158s
Background:
    Total time: 0.000000s
        device_update                            0.000000s
Bake:
    Total time: 0.000023s
        device_update                            0.000023s
Camera:
    Total time: 0.000008s
        update                                   0.000008s
        device_update                            0.000000s
Film:
    Total time: 0.000155s
        update                                   0.000155s
Integrator:
    Total time: 0.004892s
        device_update                            0.004892s
OSL:
    Total time: 0.000000s
Particles:
    Total time: 0.000008s
        device_update                            0.000008s
SVM:
    Total time: 0.498535s
        device_update                            0.498535s
Tables:
    Total time: 0.000005s
        device_update                            0.000004s
        device_update                            0.000001s
  • extends render/stats.h to gather time statistics and print a specific
This revision is now accepted and ready to land.Sep 10 2020, 1:33 PM

For the option to turn these stats on/off, it should be the same as the other stats adding in D3892 and D3566.

  • enable stats printing through the command line
  • rename "VLOG_TIMER" "scoped_callback_timer" as it is not VLOG anymore and move to util_time.h