sandey/blender
1
0
Fork 0
forked from bartvdbraak/blender
Code Pull Requests Activity

Cycles: add time statistics to scene update

Browse Source 
Gathers information for time spent in the various managers or object (Film, Camera, etc.) being updated in Scene::device_update.

The stats include the total time spent in the device_update methods as well as time spent in subroutines (e.g. bvh build, displacement, etc.).

This does not qualify as a full blown profiler, but is useful to identify potential bottleneck areas.

The stats can be enabled and printed by passing `--cycles-print-stats` on the command line to Cycles, or `-- --cycles-print-stats` to Blender.

Reviewed By: brecht

Maniphest Tasks: T79174

Differential Revision: https://developer.blender.org/D8596
This commit is contained in:
Kévin Dietrich 2020-10-01 23:16:01 +02:00
parent 342bdbc176
commit edd1164575
20 changed files with 479 additions and 82 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
intern/cycles/blender/blender_session.cpp
View File

@ -562,6 +562,10 @@ void BlenderSession::render(BL::Depsgraph &b_depsgraph_)
session->reset(buffer_params, effective_layer_samples);
/* render */
if (!b_engine.is_preview() && background && print_render_stats) {
scene->enable_update_stats();
}
session->start();
session->wait();

8
intern/cycles/render/background.cpp
View File

@ -21,9 +21,11 @@
#include "render/nodes.h"
#include "render/scene.h"
#include "render/shader.h"
#include "render/stats.h"
#include "util/util_foreach.h"
#include "util/util_math.h"
#include "util/util_time.h"
#include "util/util_types.h"
CCL_NAMESPACE_BEGIN
@ -65,6 +67,12 @@ void Background::device_update(Device *device, DeviceScene *dscene, Scene *scene
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->background.times.add_entry({"device_update", time});
}
});
device_free(device, dscene);
Shader *bg_shader = get_shader(scene);

7
intern/cycles/render/bake.cpp
View File

@ -20,6 +20,7 @@
#include "render/mesh.h"
#include "render/object.h"
#include "render/shader.h"
#include "render/stats.h"
#include "util/util_foreach.h"
@ -125,6 +126,12 @@ void BakeManager::device_update(Device * /*device*/,
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->bake.times.add_entry({"device_update", time});
}
});
KernelIntegrator *kintegrator = &dscene->data.integrator;
KernelBake *kbake = &dscene->data.bake;

14
intern/cycles/render/camera.cpp
View File

@ -18,6 +18,7 @@
#include "render/mesh.h"
#include "render/object.h"
#include "render/scene.h"
#include "render/stats.h"
#include "render/tables.h"
#include "device/device.h"
@ -27,6 +28,7 @@
#include "util/util_logging.h"
#include "util/util_math_cdf.h"
#include "util/util_task.h"
#include "util/util_time.h"
#include "util/util_vector.h"
/* needed for calculating differentials */
@ -231,6 +233,12 @@ void Camera::update(Scene *scene)
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->camera.times.add_entry({"update", time});
}
});
/* Full viewport to camera border in the viewport. */
Transform fulltoborder = transform_from_viewplane(viewport_camera_border);
Transform bordertofull = transform_inverse(fulltoborder);
@ -466,6 +474,12 @@ void Camera::device_update(Device * /* device */, DeviceScene *dscene, Scene *sc
if (!need_device_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->camera.times.add_entry({"device_update", time});
}
});
scene->lookup_tables->remove_table(&shutter_table_offset);
if (kernel_camera.shuttertime != -1.0f) {
vector<float> shutter_table;

8
intern/cycles/render/film.cpp
View File

@ -20,12 +20,14 @@
#include "render/integrator.h"
#include "render/mesh.h"
#include "render/scene.h"
#include "render/stats.h"
#include "render/tables.h"
#include "util/util_algorithm.h"
#include "util/util_foreach.h"
#include "util/util_math.h"
#include "util/util_math_cdf.h"
#include "util/util_time.h"
CCL_NAMESPACE_BEGIN
@ -408,6 +410,12 @@ void Film::device_update(Device *device, DeviceScene *dscene, Scene *scene)
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->film.times.add_entry({"update", time});
}
});
device_free(device, dscene, scene);
KernelFilm *kfilm = &dscene->data.film;

222
intern/cycles/render/geometry.cpp
View File

@ -1106,6 +1106,12 @@ void GeometryManager::device_update_preprocess(Device *device, Scene *scene, Pro
return;
}
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update_preprocess", time});
}
});
progress.set_status("Updating Meshes Flags");
/* Update flags. */
@ -1231,41 +1237,56 @@ void GeometryManager::device_update(Device *device,
bool true_displacement_used = false;
size_t total_tess_needed = 0;
foreach (Geometry *geom, scene->geometry) {
foreach (Shader *shader, geom->used_shaders) {
if (shader->need_update_geometry)
geom->need_update = true;
}
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (normals)", time});
}
});
if (geom->need_update && (geom->type == Geometry::MESH || geom->type == Geometry::VOLUME)) {
Mesh *mesh = static_cast<Mesh *>(geom);
/* Update normals. */
mesh->add_face_normals();
mesh->add_vertex_normals();
if (mesh->need_attribute(scene, ATTR_STD_POSITION_UNDISPLACED)) {
mesh->add_undisplaced();
foreach (Geometry *geom, scene->geometry) {
foreach (Shader *shader, geom->used_shaders) {
if (shader->need_update_geometry)
geom->need_update = true;
}
/* Test if we need tessellation. */
if (mesh->subdivision_type != Mesh::SUBDIVISION_NONE && mesh->num_subd_verts == 0 &&
mesh->subd_params) {
total_tess_needed++;
}
if (geom->need_update && (geom->type == Geometry::MESH || geom->type == Geometry::VOLUME)) {
Mesh *mesh = static_cast<Mesh *>(geom);
/* Test if we need displacement. */
if (mesh->has_true_displacement()) {
true_displacement_used = true;
}
/* Update normals. */
mesh->add_face_normals();
mesh->add_vertex_normals();
if (progress.get_cancel())
return;
if (mesh->need_attribute(scene, ATTR_STD_POSITION_UNDISPLACED)) {
mesh->add_undisplaced();
}
/* Test if we need tessellation. */
if (mesh->subdivision_type != Mesh::SUBDIVISION_NONE && mesh->num_subd_verts == 0 &&
mesh->subd_params) {
total_tess_needed++;
}
/* Test if we need displacement. */
if (mesh->has_true_displacement()) {
true_displacement_used = true;
}
if (progress.get_cancel())
return;
}
}
}
/* Tessellate meshes that are using subdivision */
if (total_tess_needed) {
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry(
{"device_update (adaptive subdivision)", time});
}
});
Camera *dicing_camera = scene->dicing_camera;
dicing_camera->update(scene);
@ -1302,7 +1323,12 @@ void GeometryManager::device_update(Device *device,
/* Update images needed for true displacement. */
bool old_need_object_flags_update = false;
if (true_displacement_used) {
VLOG(1) << "Updating images used for true displacement.";
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry(
{"device_update (displacement: load images)", time});
}
});
device_update_displacement_images(device, scene, progress);
old_need_object_flags_update = scene->object_manager->need_flags_update;
scene->object_manager->device_update_flags(device, dscene, scene, progress, false);
@ -1313,41 +1339,68 @@ void GeometryManager::device_update(Device *device,
mesh_calc_offset(scene);
if (true_displacement_used) {
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry(
{"device_update (displacement: copy meshes to device)", time});
}
});
device_update_mesh(device, dscene, scene, true, progress);
}
if (progress.get_cancel())
return;
device_update_attributes(device, dscene, scene, progress);
if (progress.get_cancel())
return;
/* Update displacement. */
bool displacement_done = false;
size_t num_bvh = 0;
BVHLayout bvh_layout = BVHParams::best_bvh_layout(scene->params.bvh_layout,
device->get_bvh_layout_mask());
foreach (Geometry *geom, scene->geometry) {
if (geom->need_update) {
if (geom->type == Geometry::MESH) {
Mesh *mesh = static_cast<Mesh *>(geom);
if (displace(device, dscene, scene, mesh, progress)) {
displacement_done = true;
}
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (attributes)", time});
}
if (geom->need_build_bvh(bvh_layout)) {
num_bvh++;
}
}
});
device_update_attributes(device, dscene, scene, progress);
if (progress.get_cancel())
return;
}
/* Update displacement. */
BVHLayout bvh_layout = BVHParams::best_bvh_layout(scene->params.bvh_layout,
device->get_bvh_layout_mask());
bool displacement_done = false;
size_t num_bvh = 0;
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (displacement)", time});
}
});
foreach (Geometry *geom, scene->geometry) {
if (geom->need_update) {
if (geom->type == Geometry::MESH) {
Mesh *mesh = static_cast<Mesh *>(geom);
if (displace(device, dscene, scene, mesh, progress)) {
displacement_done = true;
}
}
if (geom->need_build_bvh(bvh_layout)) {
num_bvh++;
}
}
if (progress.get_cancel())
return;
}
}
/* Device re-update after displacement. */
if (displacement_done) {
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry(
{"device_update (displacement: attributes)", time});
}
});
device_free(device, dscene);
device_update_attributes(device, dscene, scene, progress);
@ -1355,22 +1408,29 @@ void GeometryManager::device_update(Device *device,
return;
}
TaskPool pool;
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (build object BVHs)", time});
}
});
TaskPool pool;
size_t i = 0;
foreach (Geometry *geom, scene->geometry) {
if (geom->need_update) {
pool.push(function_bind(
&Geometry::compute_bvh, geom, device, dscene, &scene->params, &progress, i, num_bvh));
if (geom->need_build_bvh(bvh_layout)) {
i++;
size_t i = 0;
foreach (Geometry *geom, scene->geometry) {
if (geom->need_update) {
pool.push(function_bind(
&Geometry::compute_bvh, geom, device, dscene, &scene->params, &progress, i, num_bvh));
if (geom->need_build_bvh(bvh_layout)) {
i++;
}
}
}
}
TaskPool::Summary summary;
pool.wait_work(&summary);
VLOG(2) << "Objects BVH build pool statistics:\n" << summary.full_report();
TaskPool::Summary summary;
pool.wait_work(&summary);
VLOG(2) << "Objects BVH build pool statistics:\n" << summary.full_report();
}
foreach (Shader *shader, scene->shaders) {
shader->need_update_geometry = false;
@ -1380,21 +1440,43 @@ void GeometryManager::device_update(Device *device,
bool motion_blur = need_motion == Scene::MOTION_BLUR;
/* Update objects. */
vector<Object *> volume_objects;
foreach (Object *object, scene->objects) {
object->compute_bounds(motion_blur);
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (compute bounds)", time});
}
});
vector<Object *> volume_objects;
foreach (Object *object, scene->objects) {
object->compute_bounds(motion_blur);
}
}
if (progress.get_cancel())
return;
device_update_bvh(device, dscene, scene, progress);
if (progress.get_cancel())
return;
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry({"device_update (build scene BVH)", time});
}
});
device_update_bvh(device, dscene, scene, progress);
if (progress.get_cancel())
return;
}
device_update_mesh(device, dscene, scene, false, progress);
if (progress.get_cancel())
return;
{
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->geometry.times.add_entry(
{"device_update (copy meshes to device)", time});
}
});
device_update_mesh(device, dscene, scene, false, progress);
if (progress.get_cancel())
return;
}
need_update = false;

6
intern/cycles/render/image.cpp
View File

@ -799,6 +799,12 @@ void ImageManager::device_update(Device *device, Scene *scene, Progress &progres
return;
}
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->image.times.add_entry({"device_update", time});
}
});
TaskPool pool;
for (size_t slot = 0; slot < images.size(); slot++) {
Image *img = images[slot];

8
intern/cycles/render/integrator.cpp
View File

@ -23,6 +23,7 @@
#include "render/scene.h"
#include "render/shader.h"
#include "render/sobol.h"
#include "render/stats.h"
#include "kernel/kernel_types.h"
@ -30,6 +31,7 @@
#include "util/util_hash.h"
#include "util/util_logging.h"
#include "util/util_task.h"
#include "util/util_time.h"
CCL_NAMESPACE_BEGIN
@ -106,6 +108,12 @@ void Integrator::device_update(Device *device, DeviceScene *dscene, Scene *scene
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->integrator.times.add_entry({"device_update", time});
}
});
device_free(device, dscene);
KernelIntegrator *kintegrator = &dscene->data.integrator;

7
intern/cycles/render/light.cpp
View File

@ -25,6 +25,7 @@
#include "render/object.h"
#include "render/scene.h"
#include "render/shader.h"
#include "render/stats.h"
#include "util/util_foreach.h"
#include "util/util_hash.h"
@ -961,6 +962,12 @@ void LightManager::device_update(Device *device,
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->light.times.add_entry({"device_update", time});
}
});
VLOG(1) << "Total " << scene->lights.size() << " lights.";
/* Detect which lights are enabled, also determins if we need to update the background. */

45
intern/cycles/render/object.cpp
View File

@ -24,6 +24,7 @@
#include "render/mesh.h"
#include "render/particles.h"
#include "render/scene.h"
#include "render/stats.h"
#include "render/volume.h"
#include "util/util_foreach.h"
@ -643,15 +644,32 @@ void ObjectManager::device_update(Device *device,
if (scene->objects.size() == 0)
return;
/* Assign object IDs. */
int index = 0;
foreach (Object *object, scene->objects) {
object->index = index++;
{
/* Assign object IDs. */
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->object.times.add_entry({"device_update (assign index)", time});
}
});
int index = 0;
foreach (Object *object, scene->objects) {
object->index = index++;
}
}
/* set object transform matrices, before applying static transforms */
progress.set_status("Updating Objects", "Copying Transformations to device");
device_update_transforms(dscene, scene, progress);
{
/* set object transform matrices, before applying static transforms */
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->object.times.add_entry(
{"device_update (copy objects to device)", time});
}
});
progress.set_status("Updating Objects", "Copying Transformations to device");
device_update_transforms(dscene, scene, progress);
}
if (progress.get_cancel())
return;
@ -659,6 +677,13 @@ void ObjectManager::device_update(Device *device,
/* prepare for static BVH building */
/* todo: do before to support getting object level coords? */
if (scene->params.bvh_type == SceneParams::BVH_STATIC) {
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->object.times.add_entry(
{"device_update (apply static transforms)", time});
}
});
progress.set_status("Updating Objects", "Applying Static Transformations");
apply_static_transforms(dscene, scene, progress);
}
@ -670,6 +695,12 @@ void ObjectManager::device_update_flags(
if (!need_update && !need_flags_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->object.times.add_entry({"device_update_flags", time});
}
});
need_update = false;
need_flags_update = false;

7
intern/cycles/render/osl.cpp
View File

@ -24,6 +24,7 @@
#include "render/osl.h"
#include "render/scene.h"
#include "render/shader.h"
#include "render/stats.h"
#ifdef WITH_OSL
@ -98,6 +99,12 @@ void OSLShaderManager::device_update(Device *device,
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->osl.times.add_entry({"device_update", time});
}
});
VLOG(1) << "Total " << scene->shaders.size() << " shaders.";
device_free(device, dscene, scene);

7
intern/cycles/render/particles.cpp
View File

@ -17,6 +17,7 @@
#include "render/particles.h"
#include "device/device.h"
#include "render/scene.h"
#include "render/stats.h"
#include "util/util_foreach.h"
#include "util/util_hash.h"
@ -111,6 +112,12 @@ void ParticleSystemManager::device_update(Device *device,
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->particles.times.add_entry({"device_update", time});
}
});
VLOG(1) << "Total " << scene->particle_systems.size() << " particle systems.";
device_free(device, dscene);

29
intern/cycles/render/scene.cpp
View File

@ -95,7 +95,8 @@ Scene::Scene(const SceneParams &params_, Device *device)
default_empty(NULL),
device(device),
dscene(device),
params(params_)
params(params_),
update_stats(NULL)
{
memset((void *)&dscene.data, 0, sizeof(dscene.data));
@ -188,6 +189,7 @@ void Scene::free_memory(bool final)
delete particle_system_manager;
delete image_manager;
delete bake_manager;
delete update_stats;
}
}
@ -198,6 +200,20 @@ void Scene::device_update(Device *device_, Progress &progress)
bool print_stats = need_data_update();
if (update_stats) {
update_stats->clear();
}
scoped_callback_timer timer([this, print_stats](double time) {
if (update_stats) {
update_stats->scene.times.add_entry({"device_update", time});
if (print_stats) {
printf("Update statistics:\n%s\n", update_stats->full_report().c_str());
}
}
});
/* The order of updates is important, because there's dependencies between
* the different managers, using data computed by previous managers.
*
@ -269,7 +285,7 @@ void Scene::device_update(Device *device_, Progress &progress)
return;
progress.set_status("Updating Lookup Tables");
lookup_tables->device_update(device, &dscene);
lookup_tables->device_update(device, &dscene, this);
if (progress.get_cancel() || device->have_error())
return;
@ -293,7 +309,7 @@ void Scene::device_update(Device *device_, Progress &progress)
return;
progress.set_status("Updating Lookup Tables");
lookup_tables->device_update(device, &dscene);
lookup_tables->device_update(device, &dscene, this);
if (progress.get_cancel() || device->have_error())
return;
@ -404,6 +420,13 @@ void Scene::collect_statistics(RenderStats *stats)
image_manager->collect_statistics(stats);
}
void Scene::enable_update_stats()
{
if (!update_stats) {
update_stats = new SceneUpdateStats();
}
}
DeviceRequestedFeatures Scene::get_requested_device_features()
{
DeviceRequestedFeatures requested_features;

6
intern/cycles/render/scene.h
View File

@ -59,6 +59,7 @@ class Progress;
class BakeManager;
class BakeData;
class RenderStats;
class SceneUpdateStats;
class Volume;
/* Scene Device Data */
@ -260,6 +261,9 @@ class Scene : public NodeOwner {
/* mutex must be locked manually by callers */
thread_mutex mutex;
/* scene update statistics */
SceneUpdateStats *update_stats;
Scene(const SceneParams &params, Device *device);
~Scene();
@ -280,6 +284,8 @@ class Scene : public NodeOwner {
void collect_statistics(RenderStats *stats);
void enable_update_stats();
bool update(Progress &progress, bool &kernel_switch_needed);
/* This function is used to create a node of a specified type instead of

79
intern/cycles/render/stats.cpp
View File

@ -34,6 +34,12 @@ bool namedSizeEntryComparator(const NamedSizeEntry &a, const NamedSizeEntry &b)
return a.size > b.size;
}
bool namedTimeEntryComparator(const NamedTimeEntry &a, const NamedTimeEntry &b)
{
/* We sort in descending order. */
return a.time > b.time;
}
bool namedTimeSampleEntryComparator(const NamedNestedSampleStats &a,
const NamedNestedSampleStats &b)
{
@ -55,6 +61,14 @@ NamedSizeEntry::NamedSizeEntry(const string &name, size_t size) : name(name), si
{
}
NamedTimeEntry::NamedTimeEntry() : name(""), time(0)
{
}
NamedTimeEntry::NamedTimeEntry(const string &name, double time) : name(name), time(time)
{
}
/* Named size statistics. */
NamedSizeStats::NamedSizeStats() : total_size(0)
@ -87,6 +101,20 @@ string NamedSizeStats::full_report(int indent_level)
return result;
}
string NamedTimeStats::full_report(int indent_level)
{
const string indent(indent_level * kIndentNumSpaces, ' ');
const string double_indent = indent + indent;
string result = "";
result += string_printf("%sTotal time: %fs\n", indent.c_str(), total_time);
sort(entries.begin(), entries.end(), namedTimeEntryComparator);
foreach (const NamedTimeEntry &entry, entries) {
result += string_printf(
"%s%-40s %fs\n", double_indent.c_str(), entry.name.c_str(), entry.time);
}
return result;
}
/* Named time sample statistics. */
NamedNestedSampleStats::NamedNestedSampleStats() : name(""), self_samples(0), sum_samples(0)
@ -317,4 +345,55 @@ string RenderStats::full_report()
return result;
}
NamedTimeStats::NamedTimeStats() : total_time(0.0)
{
}
string UpdateTimeStats::full_report(int indent_level)
{
return times.full_report(indent_level + 1);
}
SceneUpdateStats::SceneUpdateStats()
{
}
string SceneUpdateStats::full_report()
{
string result = "";
result += "Scene:\n" + scene.full_report(1);
result += "Geometry:\n" + geometry.full_report(1);
result += "Light:\n" + light.full_report(1);
result += "Object:\n" + object.full_report(1);
result += "Image:\n" + image.full_report(1);
result += "Background:\n" + background.full_report(1);
result += "Bake:\n" + bake.full_report(1);
result += "Camera:\n" + camera.full_report(1);
result += "Film:\n" + film.full_report(1);
result += "Integrator:\n" + integrator.full_report(1);
result += "OSL:\n" + osl.full_report(1);
result += "Particles:\n" + particles.full_report(1);
result += "SVM:\n" + svm.full_report(1);
result += "Tables:\n" + tables.full_report(1);
return result;
}
void SceneUpdateStats::clear()
{
geometry.times.entries.clear();
image.times.entries.clear();
light.times.entries.clear();
object.times.entries.clear();
background.times.entries.clear();
bake.times.entries.clear();
camera.times.entries.clear();
film.times.entries.clear();
integrator.times.entries.clear();
osl.times.entries.clear();
particles.times.entries.clear();
scene.times.entries.clear();
svm.times.entries.clear();
tables.times.entries.clear();
}
CCL_NAMESPACE_END

64
intern/cycles/render/stats.h
View File

@ -41,6 +41,15 @@ class NamedSizeEntry {
size_t size;
};
class NamedTimeEntry {
public:
NamedTimeEntry();
NamedTimeEntry(const string &name, double time);
string name;
double time;
};
/* Container of named size entries. Used, for example, to store per-mesh memory
* usage statistics. But also keeps track of overall memory usage of the
* container.
@ -64,6 +73,29 @@ class NamedSizeStats {
vector<NamedSizeEntry> entries;
};
class NamedTimeStats {
public:
NamedTimeStats();
/* Add entry to the statistics. */
void add_entry(const NamedTimeEntry &entry)
{
total_time += entry.time;
entries.push_back(entry);
}
/* Generate full human-readable report. */
string full_report(int indent_level = 0);
/* Total time of all entries. */
double total_time;
/* NOTE: Is fine to read directly, but for adding use add_entry(), which
* makes sure all accumulating values are properly updated.
*/
vector<NamedTimeEntry> entries;
};
class NamedNestedSampleStats {
public:
NamedNestedSampleStats();
@ -155,6 +187,38 @@ class RenderStats {
NamedSampleCountStats objects;
};
class UpdateTimeStats {
public:
/* Generate full human-readable report. */
string full_report(int indent_level = 0);
NamedTimeStats times;
};
class SceneUpdateStats {
public:
SceneUpdateStats();
UpdateTimeStats geometry;
UpdateTimeStats image;
UpdateTimeStats light;
UpdateTimeStats object;
UpdateTimeStats background;
UpdateTimeStats bake;
UpdateTimeStats camera;
UpdateTimeStats film;
UpdateTimeStats integrator;
UpdateTimeStats osl;
UpdateTimeStats particles;
UpdateTimeStats scene;
UpdateTimeStats svm;
UpdateTimeStats tables;
string full_report();
void clear();
};
CCL_NAMESPACE_END
#endif /* __RENDER_STATS_H__ */

7
intern/cycles/render/svm.cpp
View File

@ -23,6 +23,7 @@
#include "render/nodes.h"
#include "render/scene.h"
#include "render/shader.h"
#include "render/stats.h"
#include "render/svm.h"
#include "util/util_foreach.h"
@ -76,6 +77,12 @@ void SVMShaderManager::device_update(Device *device,
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->svm.times.add_entry({"device_update", time});
}
});
const int num_shaders = scene->shaders.size();
VLOG(1) << "Total " << num_shaders << " shaders.";

10
intern/cycles/render/tables.cpp
View File

@ -17,8 +17,10 @@
#include "render/tables.h"
#include "device/device.h"
#include "render/scene.h"
#include "render/stats.h"
#include "util/util_logging.h"
#include "util/util_time.h"
CCL_NAMESPACE_BEGIN
@ -34,11 +36,17 @@ LookupTables::~LookupTables()
assert(lookup_tables.size() == 0);
}
void LookupTables::device_update(Device *, DeviceScene *dscene)
void LookupTables::device_update(Device *, DeviceScene *dscene, Scene *scene)
{
if (!need_update)
return;
scoped_callback_timer timer([scene](double time) {
if (scene->update_stats) {
scene->update_stats->tables.times.add_entry({"device_update", time});
}
});
VLOG(1) << "Total " << lookup_tables.size() << " lookup tables.";
if (lookup_tables.size() > 0)

2
intern/cycles/render/tables.h
View File

@ -42,7 +42,7 @@ class LookupTables {
LookupTables();
~LookupTables();
void device_update(Device *device, DeviceScene *dscene);
void device_update(Device *device, DeviceScene *dscene, Scene *scene);
void device_free(Device *device, DeviceScene *dscene);
size_t add_table(DeviceScene *dscene, vector<float> &data);

21
intern/cycles/util/util_time.h
View File

@ -17,6 +17,7 @@
#ifndef __UTIL_TIME_H__
#define __UTIL_TIME_H__
#include "util/util_function.h"
#include "util/util_string.h"
CCL_NAMESPACE_BEGIN
@ -60,6 +61,26 @@ class scoped_timer {
double time_start_;
};
class scoped_callback_timer {
public:
using callback_type = function<void(double)>;
explicit scoped_callback_timer(callback_type cb) : cb(cb)
{
}
~scoped_callback_timer()
{
if (cb) {
cb(timer.get_time());
}
}
protected:
scoped_timer timer;
callback_type cb;
};
/* Make human readable string from time, compatible with Blender metadata. */
string time_human_readable_from_seconds(const double seconds);