Mon Feb 20 03:23:19 UTC 2006  Alberto Bertogli <albertogli@telpin.com.ar>
  * Implement time logging.
  This record adds an option to log the time it took darcsweb to present a
  page. Unfortunately, because of the way it's implemented, it's impossible to
  isolate the time it takes to call darcs; however, every darcs invocation is
  logged too, to allow independant measures.
diff -rN -u old-darcsweb/config.py.sample new-darcsweb/config.py.sample
--- old-darcsweb/config.py.sample	2015-04-18 08:12:04.000000000 +0000
+++ new-darcsweb/config.py.sample	2015-04-18 08:12:04.000000000 +0000
@@ -46,6 +46,11 @@
 	# set the limit to a very high number, they will take time.
 	#searchlimit = 100
 
+	# If you want to log the times it took darcsweb to present a page,
+	# uncomment this option. The value should be a file writeable by
+	# darcsweb.
+	#logtimes = "/tmp/darcsweb_times"
+
 
 #
 # From now on, every class is a repo configuration, with the same format
diff -rN -u old-darcsweb/darcsweb.cgi new-darcsweb/darcsweb.cgi
--- old-darcsweb/darcsweb.cgi	2015-04-18 08:12:04.000000000 +0000
+++ new-darcsweb/darcsweb.cgi	2015-04-18 08:12:04.000000000 +0000
@@ -8,10 +8,11 @@
 <kay.sievers@vrfy.org> and Christian Gierke <ch@gierke.de>
 """
 
+import time
+time_begin = time.time()
 import sys
 import os
 import string
-import time
 import stat
 import sha
 import cgi
@@ -20,6 +21,7 @@
 import xml.sax
 from xml.sax.saxutils import escape as xml_escape
 import email.Utils
+time_imports = time.time() - time_begin
 
 iso_datetime = '%Y-%m-%dT%H:%M:%SZ'
 
@@ -27,6 +29,9 @@
 class config:
 	pass
 
+# list of run_darcs() invocations, for performance measures
+darcs_runs = []
+
 # exception handling
 def exc_handle(t, v, tb):
 	try:
@@ -233,6 +238,32 @@
 		realf = filter_file(config.repodir + '/' + fname)
 	return realf
 
+def log_times(cache_hit, event = None):
+	if not config.logtimes:
+		return
+
+	time_total = time.time() - time_begin
+	processing = time_total - time_imports
+	if not event:
+		event = action
+	if cache_hit:
+		event = event + " (hit)"
+	s = """\
+%s
+	total: %.3f
+	processing: %.3f
+	imports: %.3f\n""" % (event, time_total, processing, time_imports)
+
+	if darcs_runs:
+		s += "\truns:\n"
+		for params in darcs_runs:
+			s += '\t\t%s\n' % params
+	s += '\n'
+
+	lf = open(config.logtimes, 'a')
+	lf.write(s)
+	lf.close()
+
 
 #
 # generic html functions
@@ -547,6 +578,7 @@
 	os.chdir(config.repodir)
 	cmd = config.darcspath + "darcs " + params
 	inf, outf = os.popen4(cmd, 't')
+	darcs_runs.append(params)
 	return outf
 
 
@@ -2205,6 +2237,11 @@
 	else:
 		config.searchlimit = 100
 
+	if "logtimes" in dir(base):
+		config.logtimes = base.logtimes
+	else:
+		config.logtimes = None
+
 	if name and "footer" in dir(c):
 		config.footer = c.footer
 	elif "footer" in dir(base):
@@ -2225,6 +2262,7 @@
 if not form.has_key('r'):
 	fill_config()
 	do_listrepos()
+	log_times(cache_hit = 0, event = 'index')
 	sys.exit(0)
 
 # get the repo configuration and fill the config class
@@ -2252,6 +2290,7 @@
 		# we have a hit, dump and run
 		cache.dump()
 		cache.close()
+		log_times(cache_hit = 1)
 		sys.exit(0)
 	# if there is a miss, the cache will step over stdout, intercepting
 	# all "print"s and writing them to the cache file automatically
@@ -2404,3 +2443,6 @@
 if config.cachedir:
 	cache.close()
 
+log_times(cache_hit = 0)
+
+