Cycles: Add per-tile render time debug pass

Reviewers: sergey, brecht

Differential Revision: https://developer.blender.org/D2920

intern/cycles/blender/addon/engine.py

@@ -234,6 +234,7 @@ def register_passes(engine, scene, srl):
     if srl.use_pass_environment:           engine.register_pass(scene, srl, "Env",           3, "RGB",  'COLOR')
 
     crl = srl.cycles
+    if crl.pass_debug_render_time:             engine.register_pass(scene, srl, "Debug Render Time",             1, "X",   'VALUE')
     if crl.pass_debug_bvh_traversed_nodes:     engine.register_pass(scene, srl, "Debug BVH Traversed Nodes",     1, "X",   'VALUE')
     if crl.pass_debug_bvh_traversed_instances: engine.register_pass(scene, srl, "Debug BVH Traversed Instances", 1, "X",   'VALUE')
     if crl.pass_debug_bvh_intersections:       engine.register_pass(scene, srl, "Debug BVH Intersections",       1, "X",   'VALUE')

intern/cycles/blender/addon/properties.py

@@ -1189,6 +1189,12 @@ class CyclesRenderLayerSettings(bpy.types.PropertyGroup):
                 default=False,
                 update=update_render_passes,
                 )
+        cls.pass_debug_render_time = BoolProperty(
+                name="Debug Render Time",
+                description="Render time in milliseconds per sample and pixel",
+                default=False,
+                update=update_render_passes,
+                )
         cls.use_pass_volume_direct = BoolProperty(
                 name="Volume Direct",
                 description="Deliver direct volumetric scattering pass",

intern/cycles/blender/addon/ui.py

@@ -541,8 +541,9 @@ class CYCLES_RENDER_PT_layer_passes(CyclesButtonsPanel, Panel):
             sub.active = crl.use_denoising
             sub.prop(crl, "denoising_store_passes", text="Denoising")
 
+        col = layout.column()
+        col.prop(crl, "pass_debug_render_time")
         if _cycles.with_cycles_debug:
-            col = layout.column()
             col.prop(crl, "pass_debug_bvh_traversed_nodes")
             col.prop(crl, "pass_debug_bvh_traversed_instances")
             col.prop(crl, "pass_debug_bvh_intersections")

intern/cycles/blender/blender_sync.cpp

@@ -520,6 +520,7 @@ PassType BlenderSync::get_pass_type(BL::RenderPass& b_pass)
 	MAP_PASS("Debug BVH Intersections", PASS_BVH_INTERSECTIONS);
 	MAP_PASS("Debug Ray Bounces", PASS_RAY_BOUNCES);
 #endif
+	MAP_PASS("Debug Render Time", PASS_RENDER_TIME);
 #undef MAP_PASS
 
 	return PASS_NONE;
@@ -606,6 +607,10 @@ array<Pass> BlenderSync::sync_render_passes(BL::RenderLayer& b_rlay,
 		Pass::add(PASS_RAY_BOUNCES, passes);
 	}
 #endif
+	if(get_boolean(crp, "pass_debug_render_time")) {
+		b_engine.add_pass("Debug Render Time", 1, "X", b_srlay.name().c_str());
+		Pass::add(PASS_RENDER_TIME, passes);
+	}
 	if(get_boolean(crp, "use_pass_volume_direct")) {
 		b_engine.add_pass("VolumeDir", 3, "RGB", b_srlay.name().c_str());
 		Pass::add(PASS_VOLUME_DIRECT, passes);

intern/cycles/device/device_cpu.cpp

@@ -689,6 +689,8 @@ public:
 
 	void path_trace(DeviceTask &task, RenderTile &tile, KernelGlobals *kg)
 	{
+		scoped_timer timer(&tile.buffers->render_time);
+
 		float *render_buffer = (float*)tile.buffer;
 		int start_sample = tile.start_sample;
 		int end_sample = tile.start_sample + tile.num_samples;

intern/cycles/device/device_cuda.cpp

@@ -1436,6 +1436,8 @@ public:
 
 	void path_trace(DeviceTask& task, RenderTile& rtile, device_vector<WorkTile>& work_tiles)
 	{
+		scoped_timer timer(&rtile.buffers->render_time);
+
 		if(have_error())
 			return;
 

intern/cycles/device/opencl/opencl_mega.cpp

@@ -59,6 +59,8 @@ public:
 
 	void path_trace(RenderTile& rtile, int sample)
 	{
+		scoped_timer timer(&rtile.buffers->render_time);
+
 		/* Cast arguments to cl types. */
 		cl_mem d_data = CL_MEM_PTR(const_mem_map["__data"]->device_pointer);
 		cl_mem d_buffer = CL_MEM_PTR(rtile.buffer);

intern/cycles/device/opencl/opencl_split.cpp

@@ -138,6 +138,8 @@ public:
 			while(task->acquire_tile(this, tile)) {
 				if(tile.task == RenderTile::PATH_TRACE) {
 					assert(tile.task == RenderTile::PATH_TRACE);
+					scoped_timer timer(&tile.buffers->render_time);
+
 					split_kernel->path_trace(task,
 					                         tile,
 					                         kgbuffer,

intern/cycles/kernel/kernel_types.h

@@ -393,6 +393,7 @@ typedef enum PassType {
 	PASS_BVH_INTERSECTIONS,
 	PASS_RAY_BOUNCES,
 #endif
+	PASS_RENDER_TIME,
 	PASS_CATEGORY_MAIN_END = 31,
 
 	PASS_MIST = 32,

intern/cycles/render/buffers.cpp

@@ -116,7 +116,7 @@ RenderTile::RenderTile()
 
 RenderBuffers::RenderBuffers(Device *device)
 : buffer(device, "RenderBuffers", MEM_READ_WRITE),
-  map_neighbor_copied(false)
+  map_neighbor_copied(false), render_time(0.0f)
 {
 }
 
@@ -264,6 +264,12 @@ bool RenderBuffers::get_pass_rect(PassType type, float exposure, int sample, int
 				}
 			}
 #endif
+			else if(type == PASS_RENDER_TIME) {
+				float val = (float) (1000.0 * render_time/(params.width * params.height * sample));
+				for(int i = 0; i < size; i++, pixels++) {
+					pixels[0] = val;
+				}
+			}
 			else {
 				for(int i = 0; i < size; i++, in += pass_stride, pixels++) {
 					float f = *in;

intern/cycles/render/buffers.h

@@ -75,6 +75,7 @@ public:
 	/* float buffer */
 	device_vector<float> buffer;
 	bool map_neighbor_copied;
+	double render_time;
 
 	explicit RenderBuffers(Device *device);
 	~RenderBuffers();

intern/cycles/render/film.cpp

@@ -116,6 +116,10 @@ void Pass::add(PassType type, array<Pass>& passes)
 			pass.exposure = false;
 			break;
 #endif
+		case PASS_RENDER_TIME:
+			/* This pass is handled entirely on the host side. */
+			pass.components = 0;
+			break;
 
 		case PASS_DIFFUSE_COLOR:
 		case PASS_GLOSSY_COLOR:
@@ -428,6 +432,8 @@ void Film::device_update(Device *device, DeviceScene *dscene, Scene *scene)
 				kfilm->pass_ray_bounces = kfilm->pass_stride;
 				break;
 #endif
+			case PASS_RENDER_TIME:
+				break;
 
 			default:
 				assert(false);