From 4a0e02c4a8f9175ccbf696cfb3dd5fb547b18f98 Mon Sep 17 00:00:00 2001
From: Markolie <markvanalphen2@gmail.com>
Date: Thu, 20 Aug 2015 19:54:13 +0200
Subject: [PATCH] Update start of game logging

---
 code/__HELPERS/logging.dm             |  9 ++++++-
 code/__HELPERS/time.dm                | 13 ++++++++++
 code/controllers/Processes/air.dm     |  8 +++---
 code/controllers/Processes/mob.dm     |  2 +-
 code/controllers/master_controller.dm | 37 ++++++++++++++++++---------
 code/modules/awaymissions/zlevel.dm   |  9 ++++---
 6 files changed, 56 insertions(+), 22 deletions(-)

diff --git a/code/__HELPERS/logging.dm b/code/__HELPERS/logging.dm
index fd07b20e641..1635e94094a 100644
--- a/code/__HELPERS/logging.dm
+++ b/code/__HELPERS/logging.dm
@@ -84,4 +84,11 @@
 /proc/log_to_dd(text)
 	world.log << text //this comes before the config check because it can't possibly runtime
 	if(config.log_world_output)
-		diary << "\[[time_stamp()]]DD_OUTPUT: [text][log_end]"
\ No newline at end of file
+		diary << "\[[time_stamp()]]DD_OUTPUT: [text][log_end]"
+
+/**
+ * Standardized method for tracking startup times.
+ */
+/proc/log_startup_progress(var/message)
+	world << "<span class='danger'>[message]</span>"
+	world.log << message
\ No newline at end of file
diff --git a/code/__HELPERS/time.dm b/code/__HELPERS/time.dm
index af4de68fd7a..dc23a2d2782 100644
--- a/code/__HELPERS/time.dm
+++ b/code/__HELPERS/time.dm
@@ -28,4 +28,17 @@ proc/isDay(var/month, var/day)
 //returns timestamp in a sql and ISO 8601 friendly format
 /proc/SQLtime()
 	return time2text(world.realtime, "YYYY-MM-DD hh:mm:ss")
+
+/**
+ * Returns "watch handle" (really just a timestamp :V)
+ */
+/proc/start_watch()
+	return world.timeofday
+
+/**
+ * Returns number of seconds elapsed.
+ * @param wh number The "Watch Handle" from start_watch(). (timestamp)
+ */
+/proc/stop_watch(wh)
+	return round(0.1*(world.timeofday-wh),0.1)
 	
\ No newline at end of file
diff --git a/code/controllers/Processes/air.dm b/code/controllers/Processes/air.dm
index 2ae00b8a456..84b2075a151 100644
--- a/code/controllers/Processes/air.dm
+++ b/code/controllers/Processes/air.dm
@@ -27,12 +27,12 @@ var/global/datum/controller/process/air_system/air_master
 	schedule_interval = 20 // every 2 seconds
 	start_delay = 4
 	air_master = src
-
-	world << "<span class='danger'>Processing Geometry...</span>"
-	var/start_time = world.timeofday
+	
+	var/watch = start_watch()
+	log_startup_progress("Processing geometry...")
 	setup_allturfs() // Get all currently active tiles that need processing each atmos tick.
 	setup_overlays() // Assign icons and such for gas-turf-overlays
-	world << "<span class='danger'>Geometry processed in [(world.timeofday-start_time)/10] seconds!</span>"
+	log_startup_progress("  Geometry processed in [stop_watch(watch)]s.")
 
 /datum/controller/process/air_system/doWork()
 	if(kill_air)
diff --git a/code/controllers/Processes/mob.dm b/code/controllers/Processes/mob.dm
index be630a68fd8..c1dd47236f1 100644
--- a/code/controllers/Processes/mob.dm
+++ b/code/controllers/Processes/mob.dm
@@ -38,7 +38,7 @@ var/global/datum/controller/mob_system/mob_master
 	var/starttime
 
 /datum/controller/mob_system/proc/Setup()
-	world << "\red \b Mob ticker starting up."
+	log_startup_progress("Mob ticker starting up.")
 	starttime = world.timeofday
 
 /datum/controller/mob_system/proc/process()
diff --git a/code/controllers/master_controller.dm b/code/controllers/master_controller.dm
index 8ef9985f998..9b15b0fad42 100644
--- a/code/controllers/master_controller.dm
+++ b/code/controllers/master_controller.dm
@@ -27,11 +27,13 @@ datum/controller/game_controller/New()
 			del(master_controller)
 		master_controller = src
 
+	var/watch=0
 	if(!job_master)
+		watch = start_watch()
 		job_master = new /datum/controller/occupations()
 		job_master.SetupOccupations()
 		job_master.LoadJobs("config/jobs.txt")
-		world << "\red \b Job setup complete"
+		log_startup_progress("Job setup complete in [stop_watch(watch)]s.")
 
 	if(!syndicate_code_phrase)		syndicate_code_phrase	= generate_code_phrase()
 	if(!syndicate_code_response)	syndicate_code_response	= generate_code_phrase()
@@ -48,7 +50,6 @@ datum/controller/game_controller/proc/setup()
 	setupgenetics()
 	setupfactions()
 	setup_economy()
-	//SetupXenoarch()
 
 	for(var/i=0, i<max_secret_rooms, i++)
 		make_mining_asteroid_secret()
@@ -56,31 +57,43 @@ datum/controller/game_controller/proc/setup()
 	populate_spawn_points()
 
 datum/controller/game_controller/proc/setup_objects()
-	world << "\red \b Initializing objects"
-	sleep(-1)
+	var/watch = start_watch()
+	var/count = 0
+	var/overwatch = start_watch() // Overall.
+	
+	log_startup_progress("Initializing objects...")
 	for(var/atom/movable/object in world)
 		object.initialize()
+		count++
+	log_startup_progress("  Initialized [count] objects in [stop_watch(watch)]s.")
 
-	world << "\red \b Initializing pipe networks"
-	sleep(-1)
+	watch = start_watch()
+	count = 0
+	log_startup_progress("Initializing pipe networks...")
 	for(var/obj/machinery/atmospherics/machine in machines)
 		machine.build_network()
+		count++
+	log_startup_progress("  Initialized [count] pipe networks in [stop_watch(watch)]s.")
 
-	world << "\red \b Initializing atmos machinery."
-	sleep(-1)
+	watch = start_watch()
+	count = 0
+	log_startup_progress("Initializing atmospherics machinery...")
 	for(var/obj/machinery/atmospherics/unary/U in machines)
 		if(istype(U, /obj/machinery/atmospherics/unary/vent_pump))
 			var/obj/machinery/atmospherics/unary/vent_pump/T = U
 			T.broadcast_status()
+			count++
 		else if(istype(U, /obj/machinery/atmospherics/unary/vent_scrubber))
 			var/obj/machinery/atmospherics/unary/vent_scrubber/T = U
 			T.broadcast_status()
+			count++
 
-	world << "\red \b Initializations complete."
-	sleep(-1)
+	log_startup_progress("  Initialized [count] atmos devices in [stop_watch(watch)]s.")
+	log_startup_progress("Finished initializations in [stop_watch(overwatch)]s.")
 
 datum/controller/game_controller/proc/setup_starlight()
-	world << "\red \b Initializing Starlight"
+	var/watch = start_watch()
+	log_startup_progress("Initializing starlight...")
 	for(var/turf/space/S in world)
 		S.update_starlight()
-	world << "\red \b Starlight Initilization Complete"
+	log_startup_progress("  Initialized starlight in [stop_watch(watch)]s.")
diff --git a/code/modules/awaymissions/zlevel.dm b/code/modules/awaymissions/zlevel.dm
index 06689601523..b23d5e7e01e 100644
--- a/code/modules/awaymissions/zlevel.dm
+++ b/code/modules/awaymissions/zlevel.dm
@@ -3,7 +3,7 @@ proc/createRandomZlevel()
 		return
 
 	var/list/potentialRandomZlevels = list()
-	world << "<span class='userdanger'>Searching for away missions...</span>"
+	log_startup_progress("Searching for away missions...")
 	var/list/Lines = file2list("_maps/map_files/RandomZLevels/fileList.txt")
 
 	if(!Lines.len)	return
@@ -34,7 +34,8 @@ proc/createRandomZlevel()
 
 
 	if(potentialRandomZlevels.len)
-		world << "<span class='userdanger'>Loading away mission...</span>"
+		var/watch = start_watch()
+		log_startup_progress("  Loading away mission...")
 
 		var/map = pick(potentialRandomZlevels)
 		var/file = file(map)
@@ -51,8 +52,8 @@ proc/createRandomZlevel()
 				continue
 			awaydestinations.Add(L)
 
-		world << "<span class='userdanger'>Away mission loaded.</span>"
+		log_startup_progress("  Away mission loaded in [stop_watch(watch)]s.")
 
 	else
-		world << "<span class='userdanger'>No away missions found.</span>"
+		log_startup_progress("  No away missions found.")
 		return
\ No newline at end of file