Added profiling information (for engine dev mostly)

voxel_mesher.cpp

@@ -197,6 +197,8 @@ Ref<Mesh> VoxelMesher::build(const VoxelBuffer & buffer) {
     // - Slower
     // => Could be implemented in a separate class?
 
+	VOXEL_PROFILE_BEGIN("mesher_face_extraction")
+
     // Iterate 3D padded data to extract voxel faces.
     // This is the most intensive job in this class, so all required data should be as fit as possible.
     const Vector3i buffer_size = buffer.get_size();
@@ -324,6 +326,8 @@ Ref<Mesh> VoxelMesher::build(const VoxelBuffer & buffer) {
         }
     }
 
+	VOXEL_PROFILE_END("mesher_face_extraction")
+
     // Commit mesh
     Ref<Mesh> mesh_ref;
     for (unsigned int i = 0; i < MAX_MATERIALS; ++i) {
@@ -332,10 +336,15 @@ Ref<Mesh> VoxelMesher::build(const VoxelBuffer & buffer) {
             
             // Index mesh to reduce memory usage and make upload to VRAM faster
             // TODO actually, we could make it indexed from the ground up without using SurfaceTool, so we also save time!
-            st.index();
+			VOXEL_PROFILE_BEGIN("mesher_surfacetool_index")
+			st.index();
+			VOXEL_PROFILE_END("mesher_surfacetool_index")
 
-            mesh_ref = st.commit(mesh_ref);
-            st.clear();
+			VOXEL_PROFILE_BEGIN("mesher_surfacetool_commit")
+			mesh_ref = st.commit(mesh_ref);
+			VOXEL_PROFILE_END("mesher_surfacetool_commit")
+
+			st.clear();
         }
     }
 
@@ -347,7 +356,7 @@ void VoxelMesher::_bind_methods() {
 	ClassDB::bind_method(D_METHOD("set_material", "material", "id"), &VoxelMesher::set_material);
 	ClassDB::bind_method(D_METHOD("get_material:Material", "id"), &VoxelMesher::get_material);
 
-	ClassDB::bind_method(D_METHOD("set_library", "voxel_library"), &VoxelMesher::set_library);
+	ClassDB::bind_method(D_METHOD("set_library", "voxel_library:VoxelLibrary"), &VoxelMesher::set_library);
 	ClassDB::bind_method(D_METHOD("get_library:VoxelLibrary"), &VoxelMesher::get_library);
 
 	ClassDB::bind_method(D_METHOD("set_occlusion_enabled", "enable"), &VoxelMesher::set_occlusion_enabled);
@@ -356,6 +365,9 @@ void VoxelMesher::_bind_methods() {
 	ClassDB::bind_method(D_METHOD("set_occlusion_darkness", "value"), &VoxelMesher::set_occlusion_darkness);
 	ClassDB::bind_method(D_METHOD("get_occlusion_darkness"), &VoxelMesher::get_occlusion_darkness);
 
-	ClassDB::bind_method(D_METHOD("build", "voxel_buffer"), &VoxelMesher::build_ref);
+	ClassDB::bind_method(D_METHOD("build:Mesh", "voxel_buffer:VoxelBuffer"), &VoxelMesher::build_ref);
 
+#ifdef VOXEL_PROFILING
+	ClassDB::bind_method(D_METHOD("get_profiling_info"), &VoxelMesher::get_profiling_info);
+#endif
 }

voxel_mesher.h

@@ -7,6 +7,7 @@
 #include "voxel.h"
 #include "voxel_buffer.h"
 #include "voxel_library.h"
+#include "zprofiling.h"
 
 class VoxelMesher : public Reference {
 	GDCLASS(VoxelMesher, Reference)
@@ -41,6 +42,10 @@ private:
 	float _baked_occlusion_darkness;
 	bool _bake_occlusion;
 
+#ifdef VOXEL_PROFILING
+	ZProfiler _zprofiler;
+	Dictionary get_profiling_info() const { return _zprofiler.get_all_serialized_info(); }
+#endif
 };
 
 

voxel_terrain.cpp

@@ -243,13 +243,14 @@ void VoxelTerrain::update_blocks() {
 		g_viewer_block_pos = Vector3i();
 
 	// Sort updates so nearest blocks are done first
+	VOXEL_PROFILE_BEGIN("block_update_sorting")
 	_block_update_queue.sort_custom<BlockUpdateComparator>();
+	VOXEL_PROFILE_END("block_update_sorting")
 
 	// Update a bunch of blocks until none are left or too much time elapsed
 	while (!_block_update_queue.empty() && (os.get_ticks_msec() - time_before) < max_time) {
 
 		//printf("Remaining: %i\n", _block_update_queue.size());
-		//float time_before = os.get_ticks_usec();
 
 		// TODO Move this to a thread
 		// TODO Have VoxelTerrainGenerator in C++
@@ -262,16 +263,24 @@ void VoxelTerrain::update_blocks() {
 		if (!_map->has_block(block_pos)) {
 			// Create buffer
 			if(!_provider.is_null()) {
+
+				VOXEL_PROFILE_BEGIN("voxel_buffer_creation_gen")
+
 				Ref<VoxelBuffer> buffer_ref = Ref<VoxelBuffer>(memnew(VoxelBuffer));
 				const Vector3i block_size(VoxelBlock::SIZE, VoxelBlock::SIZE, VoxelBlock::SIZE);
 				buffer_ref->create(block_size.x, block_size.y, block_size.z);
 
+				VOXEL_PROFILE_END("voxel_buffer_creation_gen")
+				VOXEL_PROFILE_BEGIN("block_generation")
+
 				// Query voxel provider
 				_provider->emerge_block(buffer_ref, block_pos);
 
 				// Check script return
 				ERR_FAIL_COND(buffer_ref->get_size() != block_size);
 
+				VOXEL_PROFILE_END("block_generation")
+
 				// Store buffer
 				_map->set_block_buffer(block_pos, buffer_ref);
 
@@ -329,16 +338,23 @@ void VoxelTerrain::update_block_mesh(Vector3i block_pos) {
 		return;
 	}
 
+	VOXEL_PROFILE_BEGIN("voxel_buffer_creation_extract")
 	// Create buffer padded with neighbor voxels
 	VoxelBuffer nbuffer;
 	nbuffer.create(VoxelBlock::SIZE + 2, VoxelBlock::SIZE + 2, VoxelBlock::SIZE + 2);
+	VOXEL_PROFILE_END("voxel_buffer_creation_extract")
+
+	VOXEL_PROFILE_BEGIN("block_extraction")
 	_map->get_buffer_copy(VoxelMap::block_to_voxel(block_pos) - Vector3i(1, 1, 1), nbuffer);
+	VOXEL_PROFILE_END("block_extraction")
 
 	Vector3 block_node_pos = VoxelMap::block_to_voxel(block_pos).to_vec3();
 
 	// Build mesh (that part is the most CPU-intensive)
 	// TODO Re-use existing meshes to optimize memory cost
+	//VOXEL_PROFILE_BEGIN("meshing")
 	Ref<Mesh> mesh = _mesher->build(nbuffer);
+	//VOXEL_PROFILE_END("meshing")
 
 	// TODO Don't use nodes! Use servers directly, it's faster
 	MeshInstance * mesh_instance = block->get_mesh_instance(*this);
@@ -352,14 +368,18 @@ void VoxelTerrain::update_block_mesh(Vector3i block_pos) {
 	}
 	else {
 		// Update mesh
+		VOXEL_PROFILE_BEGIN("mesh_instance_set_mesh")
 		mesh_instance->set_mesh(mesh);
+		VOXEL_PROFILE_END("mesh_instance_set_mesh")
 	}
 
 	if(get_tree()->is_editor_hint() == false && _generate_collisions) {
 
 		// Generate collisions
 		// TODO Need to select only specific surfaces because some may not have collisions
+		VOXEL_PROFILE_BEGIN("create_trimesh_shape")
 		Ref<Shape> shape = mesh->create_trimesh_shape();
+		VOXEL_PROFILE_END("create_trimesh_shape")
 
 		StaticBody * body = block->get_physics_body(*this);
 		if(body == NULL) {
@@ -372,7 +392,9 @@ void VoxelTerrain::update_block_mesh(Vector3i block_pos) {
 		}
 		else {
 			// Update body
+			VOXEL_PROFILE_BEGIN("body_set_shape")
 			body->set_shape(0, shape);
+			VOXEL_PROFILE_END("body_set_shape")
 		}
 	}
 }
@@ -449,5 +471,9 @@ void VoxelTerrain::_bind_methods() {
 
 	ClassDB::bind_method(D_METHOD("raycast:Dictionary", "origin", "direction", "max_distance"), &VoxelTerrain::_raycast_binding, DEFVAL(100));
 
+#ifdef VOXEL_PROFILING
+	ClassDB::bind_method(D_METHOD("get_profiling_info"), &VoxelTerrain::get_profiling_info);
+#endif
+
 }
 

voxel_terrain.h

@@ -5,9 +5,7 @@
 #include "voxel_map.h"
 #include "voxel_mesher.h"
 #include "voxel_provider.h"
-
-// TODO
-//#define VOXEL_TERRAIN_PROFILING
+#include "zprofiling.h"
 
 // Infinite static terrain made of voxels.
 // It is loaded around VoxelTerrainStreamers.
@@ -88,6 +86,11 @@ private:
 
 	bool _generate_collisions;
 
+#ifdef VOXEL_PROFILING
+	ZProfiler _zprofiler;
+	Dictionary get_profiling_info() { return _zprofiler.get_all_serialized_info(); }
+#endif
+
 };
 
 #endif // VOXEL_TERRAIN_H

zprofiling.cpp

@@ -0,0 +1,149 @@
+#include "zprofiling.h"
+
+#ifdef VOXEL_PROFILING
+#include <os/os.h>
+
+//-----------------------------------------------------------------------------
+class ZProfileVar {
+public:
+	static const unsigned int BUFFERED_TIME_COUNT = 100;
+
+	ZProfileVar();
+
+	void begin(uint64_t time);
+	void end(uint64_t time);
+
+	Dictionary serialize();
+
+private:
+	float min_time;
+	float max_time;
+	float total_time;
+	float instant_time;
+	int hits;
+	float buffered_times[BUFFERED_TIME_COUNT];
+	unsigned int buffered_time_index;
+
+	float _begin_time;
+};
+
+//-----------------------------------------------------------------------------
+inline uint64_t get_time() {
+	return OS::get_singleton()->get_ticks_usec();
+	//return OS::get_singleton()->get_ticks_msec();
+}
+
+ZProfileVar::ZProfileVar() {
+	instant_time = 0.f;
+	min_time = 0.f;
+	max_time = 0.f;
+	total_time = 0.f;
+	hits = 0;
+	_begin_time = 0.f;
+	for(unsigned int i = 0; i < BUFFERED_TIME_COUNT; ++i)
+		buffered_times[i] = 0;
+	buffered_time_index = 0;
+}
+
+void ZProfileVar::begin(uint64_t time) {
+	_begin_time = time;
+}
+
+void ZProfileVar::end(uint64_t time) {
+	instant_time = time - _begin_time;
+
+	if(hits == 0)
+	{
+		min_time = instant_time;
+		max_time = instant_time;
+	}
+	else
+	{
+		if(instant_time < min_time)
+			min_time = instant_time;
+
+		if(instant_time > max_time)
+			max_time = instant_time;
+	}
+
+	total_time += instant_time;
+
+	buffered_times[buffered_time_index] = instant_time;
+	++buffered_time_index;
+	if(buffered_time_index >= BUFFERED_TIME_COUNT)
+		buffered_time_index = 0;
+
+	++hits;
+}
+
+Dictionary ZProfileVar::serialize() {
+	Dictionary d;
+	d["instant_time"] = instant_time;
+	d["min_time"] = min_time;
+	d["max_time"] = max_time;
+	d["mean_time"] = hits > 0 ? total_time / static_cast<float>(hits) : 0;
+	d["total_time"] = total_time;
+	d["hits"] = hits;
+
+	Array a;
+	for(unsigned int i = 0; i < BUFFERED_TIME_COUNT; ++i) {
+		a.append(buffered_times[i]);
+	}
+	d["buffered_times"] = a;
+	d["buffered_time_index"] = buffered_time_index;
+
+	return d;
+}
+
+//-----------------------------------------------------------------------------
+//ZProfiler g_zprofiler;
+
+//ZProfiler & ZProfiler::get() {
+//	return g_zprofiler;
+//}
+
+ZProfiler::~ZProfiler() {
+	const String * key = NULL;
+	while (key = _vars.next(key)) {
+		ZProfileVar * v = _vars.get(*key);
+		memdelete(v);
+	}
+}
+
+ZProfileVar * ZProfiler::get_var(String key) {
+	ZProfileVar * v = NULL;
+	ZProfileVar ** pv = _vars.getptr(key);
+	if(pv == NULL) {
+		v = memnew(ZProfileVar);
+		_vars[key] = v;
+	}
+	else {
+		v = *pv;
+	}
+	return v;
+}
+
+void ZProfiler::begin(String key) {
+	ZProfileVar * v = get_var(key);
+	v->begin(get_time());
+}
+
+void ZProfiler::end(String key) {
+	uint64_t time = get_time();
+	ZProfileVar * v = get_var(key);
+	v->end(time);
+}
+
+Dictionary ZProfiler::get_all_serialized_info() const {
+	Dictionary d;
+	const String * key = NULL;
+	while (key = _vars.next(key)) {
+		ZProfileVar * v = _vars.get(*key);
+		d[*key] = v->serialize();
+	}
+	return d;
+}
+
+
+#endif // VOXEL_PROFILING
+

zprofiling.h

@@ -0,0 +1,41 @@
+#ifndef VOXEL_PROFILING_H
+#define VOXEL_PROFILING_H
+
+#define VOXEL_PROFILING
+
+#ifdef VOXEL_PROFILING
+
+#include <ustring.h>
+#include <dictionary.h>
+#include <hash_map.h>
+
+#define VOXEL_PROFILE_BEGIN(_key) _zprofiler.begin(_key);
+#define VOXEL_PROFILE_END(_key) _zprofiler.end(_key);
+
+class ZProfileVar;
+
+class ZProfiler {
+public:
+	//static ZProfiler & get();
+	~ZProfiler();
+
+	void begin(String key);
+	void end(String key);
+
+	Dictionary get_all_serialized_info() const;
+
+private:
+	//ZProfiler();
+	ZProfileVar * get_var(String key);
+
+	HashMap<String, ZProfileVar*> _vars;
+};
+
+#else
+
+#define VOXEL_PROFILE_BEGIN(_key) //
+#define VOXEL_PROFILE_END(_key) //
+
+#endif
+
+#endif // VOXEL_PROFILING_H