Add tracing scopes to the mission load code

asarium · asarium · commit abdef9f7b0f1 · 2017-03-28T17:23:22.000+02:00
This makes it easier to determine what takes the most time while loading
the mission (loading models) and how we could optimize that load time
(optimize model loading).

This is not a bug fix but it also shouldn't cause any regressions since
there are no actual code changes so this could be merged before the
release of 3.8.
diff --git a/code/bmpman/bmpman.cpp b/code/bmpman/bmpman.cpp
@@ -35,6 +35,7 @@
 #include "ship/ship.h"
 #include "tgautils/tgautils.h"
 #include "tracing/Monitor.h"
+#include "tracing/tracing.h"
 
 #include <ctype.h>
 #include <limits.h>
@@ -2577,6 +2578,8 @@ void bm_page_in_start() {
 }
 
 void bm_page_in_stop() {
+	TRACE_SCOPE(tracing::PageInStop);
+
 	int i;
 
 #ifndef NDEBUG
@@ -2593,6 +2596,7 @@ void bm_page_in_stop() {
 	for (i = 0; i < MAX_BITMAPS; i++) {
 		if ((bm_bitmaps[i].type != BM_TYPE_NONE) && (bm_bitmaps[i].type != BM_TYPE_RENDER_TARGET_DYNAMIC) && (bm_bitmaps[i].type != BM_TYPE_RENDER_TARGET_STATIC)) {
 			if (bm_bitmaps[i].preloaded) {
+				TRACE_SCOPE(tracing::PageInSingleBitmap);
 				if (bm_preloading) {
 					if (!gr_preload(bm_bitmaps[i].handle, (bm_bitmaps[i].preloaded == 2))) {
 						mprintf(("Out of VRAM.  Done preloading.\n"));
diff --git a/code/gamesnd/gamesnd.cpp b/code/gamesnd/gamesnd.cpp
@@ -15,6 +15,7 @@
 #include "parse/parselo.h"
 #include "sound/ds.h"
 #include "species_defs/species_defs.h"
+#include "tracing/tracing.h"
 
 SCP_vector<game_snd>	Snds;
 SCP_vector<game_snd>	Snds_iface;
diff --git a/code/mission/missionload.cpp b/code/mission/missionload.cpp
@@ -21,7 +21,7 @@
 #include "missionui/missionshipchoice.h"
 #include "playerman/managepilot.h"
 #include "ui/ui.h"
-
+#include "tracing/tracing.h"
 
 
 extern mission The_mission;  // need to send this info to the briefing
@@ -82,6 +82,8 @@ void ml_update_recent_missions(char *filename)
 // returns -1 if failed, 0 if successful
 int mission_load(char *filename_ext)
 {
+	TRACE_SCOPE(tracing::LoadMissionLoad);
+
 	char filename[MAX_PATH_LEN], *ext;
 
 	if ( (filename_ext != NULL) && (Game_current_mission_filename != filename_ext) )
diff --git a/code/model/modelcollide.cpp b/code/model/modelcollide.cpp
@@ -18,6 +18,7 @@
 #include "math/vecmat.h"
 #include "model/model.h"
 #include "model/modelsinc.h"
+#include "tracing/tracing.h"
 #include "tracing/Monitor.h"
 
 
@@ -731,6 +732,8 @@ void model_collide_parse_bsp_flatpoly(bsp_collision_leaf *leaf, SCP_vector<model
 
 void model_collide_parse_bsp(bsp_collision_tree *tree, void *model_ptr, int version)
 {
+	TRACE_SCOPE(tracing::ModelParseBSPTree);
+
 	ubyte *p = (ubyte *)model_ptr;
 	ubyte *next_p;
 
diff --git a/code/model/modelinterp.cpp b/code/model/modelinterp.cpp
@@ -35,6 +35,7 @@
 #include "ship/shipfx.h"
 #include "weapon/shockwave.h"
 #include "tracing/Monitor.h"
+#include "tracing/tracing.h"
 
 #include <limits.h>
 
@@ -2255,6 +2256,8 @@ bool model_interp_config_buffer(indexed_vertex_source *vert_src, vertex_buffer *
 
 void interp_configure_vertex_buffers(polymodel *pm, int mn)
 {
+	TRACE_SCOPE(tracing::ModelConfigureVertexBuffers);
+
 	int i, j, first_index;
 	uint total_verts = 0;
 	SCP_vector<int> vertex_list;
@@ -2501,6 +2504,8 @@ void interp_fill_detail_index_buffer(SCP_vector<int> &submodel_list, polymodel *
 
 void interp_create_detail_index_buffer(polymodel *pm, int detail_num)
 {
+	TRACE_SCOPE(tracing::ModelCreateDetailIndexBuffers);
+
 	SCP_vector<int> submodel_list;
 
 	submodel_list.clear();
@@ -2523,6 +2528,8 @@ void interp_create_detail_index_buffer(polymodel *pm, int detail_num)
 
 void interp_create_transparency_index_buffer(polymodel *pm, int mn)
 {
+	TRACE_SCOPE(tracing::ModelCreateTransparencyIndexBuffer);
+
 	const int NUM_VERTS_PER_TRI = 3;
 
 	bsp_info *sub_model = &pm->submodel[mn];
diff --git a/code/model/modeloctant.cpp b/code/model/modeloctant.cpp
@@ -18,6 +18,7 @@
 #include "math/vecmat.h"
 #include "model/model.h"
 #include "model/modelsinc.h"
+#include "tracing/tracing.h"
 
 // returns 1 if a point is in an octant.
 int point_in_octant( polymodel * pm, model_octant * oct, vec3d *vert )
@@ -311,6 +312,8 @@ void model_octant_find_faces( polymodel * pm, model_octant * oct )
 // Creates the octants for a given polygon model
 void model_octant_create( polymodel * pm )
 {
+	TRACE_SCOPE(tracing::ModelCreateOctants);
+
 	vec3d min, max, center;
 	int i, x, y, z;
 
diff --git a/code/model/modelread.cpp b/code/model/modelread.cpp
@@ -36,6 +36,8 @@
 #include "render/3dinternal.h"
 #include "ship/ship.h"
 #include "weapon/weapon.h"
+#include "tracing/tracing.h"
+
 #include <algorithm>
 
 flag_def_list model_render_flags[] =
@@ -877,6 +879,8 @@ void create_vertex_buffer(polymodel *pm)
 		return;
 	}
 
+	TRACE_SCOPE(tracing::ModelCreateVertexBuffers);
+
 	int i;
 
 	// determine the size and configuration of each buffer segment
@@ -1061,7 +1065,9 @@ int read_model_file(polymodel * pm, const char *filename, int n_subsystems, mode
 		}
 
 		return -1;
-	}		
+	}
+
+	TRACE_SCOPE(tracing::ReadModelFile);
 
 	// generate checksum for the POF
 	cfseek(fp, 0, SEEK_SET);	
@@ -2637,7 +2643,9 @@ int model_load(const  char *filename, int n_subsystems, model_subsystem *subsyst
 	if ( num == -1 )	{
 		Error( LOCATION, "Too many models" );
 		return -1;
-	}	
+	}
+
+	TRACE_SCOPE(tracing::LoadModelFile);
 
 	mprintf(( "Loading model '%s' into slot '%i'\n", filename, num ));
 
@@ -2846,6 +2854,8 @@ int model_load(const  char *filename, int n_subsystems, model_subsystem *subsyst
 	model_octant_create( pm );
 
 	if ( !Cmdline_old_collision_sys ) {
+		TRACE_SCOPE(tracing::ModelParseAllBSPTrees);
+
 		for ( i = 0; i < pm->n_models; ++i ) {
 			pm->submodel[i].collision_tree_index = model_create_bsp_collision_tree();
 			bsp_collision_tree *tree = model_get_bsp_collision_tree(pm->submodel[i].collision_tree_index);
diff --git a/code/ship/ship.cpp b/code/ship/ship.cpp
@@ -85,6 +85,7 @@
 #include "weapon/swarm.h"
 #include "weapon/weapon.h"
 #include "tracing/Monitor.h"
+#include "tracing/tracing.h"
 
 using namespace Ship;
 
@@ -16114,6 +16115,8 @@ int get_max_ammo_count_for_turret_bank(ship_weapon *swp, int bank, int ammo_type
  */
 void ship_page_in()
 {
+	TRACE_SCOPE(tracing::ShipPageIn);
+
 	int i, j, k;
 	int num_subsystems_needed = 0;
 
diff --git a/code/sound/sound.cpp b/code/sound/sound.cpp
@@ -25,6 +25,7 @@
 #include "sound/ds3d.h"
 #include "sound/dscap.h"
 #include "tracing/Monitor.h"
+#include "tracing/tracing.h"
 
 #include "globalincs/pstypes.h"
 
@@ -313,6 +314,7 @@ int snd_load( game_snd *gs, int allow_hardware_load )
 
 	si = &snd->info;
 
+	TRACE_SCOPE(tracing::LoadSound);
 
 	std::unique_ptr<ffmpeg::WaveFile> audio_file(new ffmpeg::WaveFile());
 
diff --git a/code/tracing/categories.cpp b/code/tracing/categories.cpp
@@ -91,4 +91,24 @@ Category CutsceneProcessAudioData("Process audio data", false);
 Category CutsceneFFmpegVideoDecoder("FFmpeg decode video", false);
 Category CutsceneFFmpegAudioDecoder("FFmpeg decode video", false);
 
+Category LoadMissionLoad("Load mission", false);
+Category LoadPostMissionLoad("Mission load post processing", false);
+Category LoadModelFile("Load model file", false);
+Category ReadModelFile("Read model file", false);
+Category ModelCreateVertexBuffers("Create model vertex buffers", false);
+Category ModelCreateOctants("Create model octants", false);
+Category ModelParseAllBSPTrees("Parse all BSP trees", false);
+Category ModelParseBSPTree("Parse BSP tree", false);
+Category ModelConfigureVertexBuffers("Model configure vertex buffers", false);
+Category ModelCreateTransparencyIndexBuffer("Model create transparency buffer", false);
+Category ModelCreateDetailIndexBuffers("Model create detail index buffers", false);
+
+Category PreloadMissionSounds("Preload mission sounds", false);
+Category LoadSound("Load Sound", false);
+
+Category LevelPageIn("Level page in", false);
+Category PageInStop("Finish page in", false);
+Category PageInSingleBitmap("Page in single bitmap", false);
+Category ShipPageIn("Ship page in", false);
+Category WeaponPageIn("Weapon page in", false);
 }
diff --git a/code/tracing/categories.h b/code/tracing/categories.h
@@ -102,6 +102,29 @@ extern Category CutsceneProcessAudioData;
 
 extern Category CutsceneFFmpegVideoDecoder;
 extern Category CutsceneFFmpegAudioDecoder;
+
+// Loading scopes
+extern Category LoadMissionLoad;
+extern Category LoadPostMissionLoad;
+extern Category LoadModelFile;
+extern Category ReadModelFile;
+extern Category ModelCreateVertexBuffers;
+extern Category ModelCreateOctants;
+extern Category ModelParseAllBSPTrees;
+extern Category ModelParseBSPTree;
+extern Category ModelConfigureVertexBuffers;
+extern Category ModelCreateTransparencyIndexBuffer;
+extern Category ModelCreateDetailIndexBuffers;
+
+extern Category PreloadMissionSounds;
+extern Category LoadSound;
+
+extern Category LevelPageIn;
+extern Category PageInStop;
+extern Category PageInSingleBitmap;
+extern Category ShipPageIn;
+extern Category WeaponPageIn;
+
 }
 
 #endif // _TRACING_CATEGORIES_H
diff --git a/code/weapon/weapons.cpp b/code/weapon/weapons.cpp
@@ -56,6 +56,7 @@
 #include "particle/effects/BeamPiercingEffect.h"
 #include "particle/effects/ParticleEmitterEffect.h"
 #include "tracing/Monitor.h"
+#include "tracing/tracing.h"
 
 // Since SSMs are parsed after weapons, if we want to allow SSM strikes to be specified by name, we need to store those names until after SSMs are parsed.
 typedef struct delayed_ssm_data {
@@ -6355,6 +6356,8 @@ void weapon_mark_as_used(int weapon_type)
 
 void weapons_page_in()
 {
+	TRACE_SCOPE(tracing::WeaponPageIn);
+
 	int i, j, idx;
 
 	Assert( used_weapons != NULL );
diff --git a/freespace2/freespace.cpp b/freespace2/freespace.cpp
@@ -1272,17 +1272,21 @@ void freespace_mission_load_stuff()
 		game_busy( NOX("** unloading interface sounds **") );
 		gamesnd_unload_interface_sounds();		// unload interface sounds from memory
 
-		game_busy( NOX("** preloading common game sounds **") );
-		gamesnd_preload_common_sounds();			// load in sounds that are expected to play
+		{
+			TRACE_SCOPE(tracing::PreloadMissionSounds);
 
-		if (Cmdline_snd_preload) {
-			game_busy( NOX("** preloading gameplay sounds **") );
-			gamesnd_load_gameplay_sounds();			// preload in gameplay sounds if wanted
-		}
+			game_busy( NOX("** preloading common game sounds **") );
+			gamesnd_preload_common_sounds();			// load in sounds that are expected to play
+
+			if (Cmdline_snd_preload) {
+				game_busy( NOX("** preloading gameplay sounds **") );
+				gamesnd_load_gameplay_sounds();			// preload in gameplay sounds if wanted
+			}
 
-		game_busy( NOX("** assigning sound environment for mission **") );
-		ship_assign_sound_all();	// assign engine sounds to ships
-		game_assign_sound_environment();	 // assign the sound environment for this mission
+			game_busy( NOX("** assigning sound environment for mission **") );
+			ship_assign_sound_all();	// assign engine sounds to ships
+			game_assign_sound_environment();	 // assign the sound environment for this mission
+		}
 
 		obj_merge_created_list();
 
@@ -1317,6 +1321,8 @@ void freespace_mission_load_stuff()
  */
 void game_post_level_init()
 {
+	TRACE_SCOPE(tracing::LoadPostMissionLoad);
+
 	HUD_init();
 	hud_setup_escort_list();
 	mission_hotkey_set_defaults();	// set up the default hotkeys (from mission file)
diff --git a/freespace2/levelpaging.cpp b/freespace2/levelpaging.cpp
@@ -12,6 +12,8 @@
 #include "freespace.h"
 #include "levelpaging.h"
 
+#include "tracing/tracing.h"
+
 
 // All the page in functions
 extern void ship_page_in();
@@ -38,6 +40,8 @@ namespace particle
 // loaded mission.  Call game_busy() occasionally...
 void level_page_in()
 {
+	TRACE_SCOPE(tracing::LevelPageIn);
+
 	// Most important ones first
 	game_busy( NOX("*** paging in ships ***") );
 	ship_page_in();
