Rev 2527: make profiling information easier to view and better documented (Clatworthy) in file:///home/pqm/archives/thelove/bzr/%2Btrunk/
Canonical.com Patch Queue Manager
pqm at pqm.ubuntu.com
Wed Jun 13 07:16:30 BST 2007
At file:///home/pqm/archives/thelove/bzr/%2Btrunk/
------------------------------------------------------------
revno: 2527
revision-id: pqm at pqm.ubuntu.com-20070613061627-xx5xk6q0oxcy1etm
parent: pqm at pqm.ubuntu.com-20070613035912-pvm3sni5chbome9j
parent: aaron.bentley at utoronto.ca-20070613054325-3sma3rfutgyj9ktm
committer: Canonical.com Patch Queue Manager<pqm at pqm.ubuntu.com>
branch nick: +trunk
timestamp: Wed 2007-06-13 07:16:27 +0100
message:
make profiling information easier to view and better documented (Clatworthy)
added:
bzrlib/tests/test_lsprof.py test_lsprof.py-20070606095601-bctdndm8yhc0cqnc-1
doc/developers/profiling.txt profiling.txt-20070531045713-j15mxufywgzwdeu8-1
modified:
NEWS NEWS-20050323055033-4e00b5db738777ff
bzrlib/commands.py bzr.py-20050309040720-d10f4714595cf8c3
bzrlib/help_topics.py help_topics.py-20060920210027-rnim90q9e0bwxvy4-1
bzrlib/lsprof.py lsprof.py-20051208071030-833790916798ceed
bzrlib/tests/__init__.py selftest.py-20050531073622-8d0e3c8845c97a64
bzrlib/tests/test_selftest.py test_selftest.py-20051202044319-c110a115d8c0456a
doc/developers/index.txt index.txt-20070508041241-qznziunkg0nffhiw-1
------------------------------------------------------------
revno: 2493.2.11
merged: aaron.bentley at utoronto.ca-20070613054325-3sma3rfutgyj9ktm
parent: abentley at panoramicfeedback.com-20070612181006-kinkxenc2dmgb4lp
committer: Aaron Bentley <aaron.bentley at utoronto.ca>
branch nick: bzr.kcachegrind
timestamp: Wed 2007-06-13 01:43:25 -0400
message:
Compensate for brittle requireFeature behavior
------------------------------------------------------------
revno: 2493.2.10
merged: abentley at panoramicfeedback.com-20070612181006-kinkxenc2dmgb4lp
parent: abentley at panoramicfeedback.com-20070612145707-6ul10rmeln23my4f
parent: pqm at pqm.ubuntu.com-20070612172839-mr0bjmyfguskc0tg
committer: Aaron Bentley <abentley at panoramicfeedback.com>
branch nick: bzr.kcachegrind
timestamp: Tue 2007-06-12 14:10:06 -0400
message:
Merge bzr.dev
------------------------------------------------------------
revno: 2493.2.9
merged: abentley at panoramicfeedback.com-20070612145707-6ul10rmeln23my4f
parent: abentley at panoramicfeedback.com-20070612145111-yuwn0kkaj0j2csar
parent: pqm at pqm.ubuntu.com-20070612060727-v8nd5etbkay15fm2
committer: Aaron Bentley <abentley at panoramicfeedback.com>
branch nick: bzr.kcachegrind
timestamp: Tue 2007-06-12 10:57:07 -0400
message:
Merge bzr.dev
------------------------------------------------------------
revno: 2493.2.8
merged: abentley at panoramicfeedback.com-20070612145111-yuwn0kkaj0j2csar
parent: abentley at panoramicfeedback.com-20070612144646-li182vnwwb2utpjx
committer: Aaron Bentley <abentley at panoramicfeedback.com>
branch nick: bzr.kcachegrind
timestamp: Tue 2007-06-12 10:51:11 -0400
message:
Convert old lsprof tests to require new LSProf Feature instead of skipping
------------------------------------------------------------
revno: 2493.2.7
merged: abentley at panoramicfeedback.com-20070612144646-li182vnwwb2utpjx
parent: abentley at panoramicfeedback.com-20070612141350-nk6niovgz6ne2vit
committer: Aaron Bentley <abentley at panoramicfeedback.com>
branch nick: bzr.kcachegrind
timestamp: Tue 2007-06-12 10:46:46 -0400
message:
Add info to --lsprof-file entry in global options
------------------------------------------------------------
revno: 2493.2.6
merged: abentley at panoramicfeedback.com-20070612141350-nk6niovgz6ne2vit
parent: ian.clatworthy at internode.on.net-20070606115137-iq6sk13d8p356bo8
committer: Aaron Bentley <abentley at panoramicfeedback.com>
branch nick: bzr.kcachegrind
timestamp: Tue 2007-06-12 10:13:50 -0400
message:
Make LSProf into a Feature required by the appropriate tests
------------------------------------------------------------
revno: 2493.2.5
merged: ian.clatworthy at internode.on.net-20070606115137-iq6sk13d8p356bo8
parent: ian.clatworthy at internode.on.net-20070606110604-ou544q3egg7tko88
committer: Ian Clatworthy <ian.clatworthy at internode.on.net>
branch nick: bzr.kcachegrind
timestamp: Wed 2007-06-06 21:51:37 +1000
message:
explicit format saving test
------------------------------------------------------------
revno: 2493.2.4
merged: ian.clatworthy at internode.on.net-20070606110604-ou544q3egg7tko88
parent: ian.clatworthy at internode.on.net-20070606104508-q2i41r4r23xkaebs
committer: Ian Clatworthy <ian.clatworthy at internode.on.net>
branch nick: bzr.kcachegrind
timestamp: Wed 2007-06-06 21:06:04 +1000
message:
removed old profiling data saving code from UI layer
------------------------------------------------------------
revno: 2493.2.3
merged: ian.clatworthy at internode.on.net-20070606104508-q2i41r4r23xkaebs
parent: ian.clatworthy at internode.on.net-20070531045925-jdx7px85ktqxxzox
committer: Ian Clatworthy <ian.clatworthy at internode.on.net>
branch nick: bzr.kcachegrind
timestamp: Wed 2007-06-06 20:45:08 +1000
message:
changes requested in jameinel's review incorporated
------------------------------------------------------------
revno: 2493.2.2
merged: ian.clatworthy at internode.on.net-20070531045925-jdx7px85ktqxxzox
parent: ian.clatworthy at internode.on.net-20070528020825-ytop085jnocvmx3q
committer: Ian Clatworthy <ian.clatworthy at internode.on.net>
branch nick: bzr.kcachegrind
timestamp: Thu 2007-05-31 14:59:25 +1000
message:
Incorporate feedback from Robert Collins
------------------------------------------------------------
revno: 2493.2.1
merged: ian.clatworthy at internode.on.net-20070528020825-ytop085jnocvmx3q
parent: pqm at pqm.ubuntu.com-20070524165738-rzs9lvgoqk20vls9
committer: Ian Clatworthy <ian.clatworthy at internode.on.net>
branch nick: bzr.kcachegrind
timestamp: Mon 2007-05-28 12:08:25 +1000
message:
make profiling information easier to view and better documented
=== added file 'bzrlib/tests/test_lsprof.py'
--- a/bzrlib/tests/test_lsprof.py 1970-01-01 00:00:00 +0000
+++ b/bzrlib/tests/test_lsprof.py 2007-06-13 05:43:25 +0000
@@ -0,0 +1,86 @@
+# Copyright (C) 2005, 2006 Canonical Ltd
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation; either version 2 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program; if not, write to the Free Software
+# Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA
+
+"""Tests for profiling data collection."""
+
+
+import cPickle
+import os
+
+import bzrlib
+from bzrlib import tests
+
+
+class LSProf(tests.Feature):
+
+ def available(self):
+ try:
+ from bzrlib import lsprof
+ except ImportError:
+ return False
+ else:
+ return True
+
+
+_TXT_HEADER = " CallCount Recursive Total(ms) " + \
+ "Inline(ms) module:lineno(function)\n"
+
+
+def _junk_callable():
+ "A simple routine to profile."
+ result = sorted(['abc', 'def', 'ghi'])
+
+
+def _collect_stats():
+ "Collect and return some dummy profile data."
+ from bzrlib.lsprof import profile
+ ret, stats = profile(_junk_callable)
+ return stats
+
+
+class TestStatsSave(tests.TestCaseInTempDir):
+
+ def setUp(self):
+ self.requireFeature(LSProf())
+ super(tests.TestCaseInTempDir, self).setUp()
+ self.stats = _collect_stats()
+
+ def _tempfile(self, ext):
+ dir = self.test_dir
+ return os.path.join(dir, "tmp_profile_data." + ext)
+
+ def test_stats_save_to_txt(self):
+ f = self._tempfile("txt")
+ self.stats.save(f)
+ lines = open(f).readlines()
+ self.assertEqual(lines[0], _TXT_HEADER)
+
+ def test_stats_save_to_callgrind(self):
+ f = self._tempfile("callgrind")
+ self.stats.save(f)
+ lines = open(f).readlines()
+ self.assertEqual(lines[0], "events: Ticks\n")
+ # Test explicit format nommination
+ f2 = self._tempfile("txt")
+ self.stats.save(f2, format="callgrind")
+ lines2 = open(f2).readlines()
+ self.assertEqual(lines2[0], "events: Ticks\n")
+
+ def test_stats_save_to_pickle(self):
+ f = self._tempfile("pkl")
+ self.stats.save(f)
+ data1 = cPickle.load(open(f))
+ self.assertEqual(type(data1), bzrlib.lsprof.Stats)
=== added file 'doc/developers/profiling.txt'
--- a/doc/developers/profiling.txt 1970-01-01 00:00:00 +0000
+++ b/doc/developers/profiling.txt 2007-05-31 04:59:25 +0000
@@ -0,0 +1,32 @@
+Profiling
+=========
+
+Bazaar has some built-in support for collecting and saving profiling
+information. In the simpliest case, the --lsprof option can be used as
+shown below::
+
+ bzr --lsprof ...
+
+This will dump the profiling information to stdout before exiting.
+Alternatively, the --lsprof-file option can be used to specify a filename
+to save the profiling data into to. By default, profiling data saved to a
+file is a pickled Python object making it possible to reload the data and
+do with it what you will. For convenience though:
+
+* if the filename ends in ".txt", it will be dumped in a text format.
+
+* if the filename ends in ".callgrind", it will be converted to a format
+ loadable by the KCacheGrind visualization tool.
+
+Here is an example of how to use the --lsprof-file option in combination
+with KCacheGrind to visualize what the "status" command is doing::
+
+ bzr --lsprof-file status001.callgrind status
+ kcachegrind status001.callgrind &
+
+.. Note:: bzr also has a --profile option that uses the hotshot profiler
+ instead of the lsprof profiler. The hotshot profiler can be useful
+ though the lsprof one is generally recommended. See
+ http://docs.python.org/lib/node795.html.
+
+
=== modified file 'NEWS'
--- a/NEWS 2007-06-12 16:21:40 +0000
+++ b/NEWS 2007-06-12 18:10:06 +0000
@@ -1,5 +1,14 @@
IN DEVELOPMENT
+ IMPROVEMENTS:
+
+ * The --lsprof-file option now dumps a text rendering of the profiling
+ information if the filename ends in ".txt". It will also convert the
+ profiling information to a format suitable for KCacheGrind if the
+ output filename ends in ".callgrind". Fixes to the lsprofcalltree
+ conversion process by Jean Paul Calderone and Itamar were also merged.
+ See http://ddaa.net/blog/python/lsprof-calltree. (Ian Clatworthy)
+
bzr 0.17rc1 2007-06-12
NOTES WHEN UPGRADING:
=== modified file 'bzrlib/commands.py'
--- a/bzrlib/commands.py 2007-04-30 21:03:34 +0000
+++ b/bzrlib/commands.py 2007-06-06 11:06:04 +0000
@@ -540,8 +540,7 @@
if filename is None:
stats.pprint()
else:
- stats.freeze()
- cPickle.dump(stats, open(filename, 'w'), 2)
+ stats.save(filename)
print 'Profile data written to %r.' % filename
return ret
=== modified file 'bzrlib/help_topics.py'
--- a/bzrlib/help_topics.py 2007-05-14 20:42:47 +0000
+++ b/bzrlib/help_topics.py 2007-06-12 14:46:46 +0000
@@ -193,7 +193,12 @@
--profile Profile execution using the hotshot profiler
--lsprof Profile execution using the lsprof profiler
--lsprof-file Profile execution using the lsprof profiler, and write the
- results to a specified file.
+ results to a specified file. If the filename ends with ".txt",
+ text format will be used. If the filename ends with
+ ".callgrind", output will be formatted for use with KCacheGrind.
+ Otherwise, the output will be a pickle.
+
+See doc/developers/profiling.txt for more information on profiling.
Note: --version must be supplied before any command.
"""
=== modified file 'bzrlib/lsprof.py'
--- a/bzrlib/lsprof.py 2006-09-08 18:46:29 +0000
+++ b/bzrlib/lsprof.py 2007-06-06 10:45:08 +0000
@@ -3,6 +3,8 @@
# I made one modification to profile so that it returns a pair
# instead of just the Stats object
+import cPickle
+import os
import sys
import thread
import threading
@@ -104,8 +106,42 @@
"""Output profiling data in calltree format (for KCacheGrind)."""
_CallTreeFilter(self.data).output(file)
+ def save(self, filename, format=None):
+ """Save profiling data to a file.
+
+ :param filename: the name of the output file
+ :param format: 'txt' for a text representation;
+ 'callgrind' for calltree format;
+ otherwise a pickled Python object. A format of None indicates
+ that the format to use is to be found from the extension of
+ filename.
+ """
+ if format is None:
+ ext = os.path.splitext(filename)[1]
+ if len(ext) > 1:
+ format = ext[1:]
+ outfile = open(filename, 'wb')
+ try:
+ if format == "callgrind":
+ self.calltree(outfile)
+ elif format == "txt":
+ self.pprint(file=outfile)
+ else:
+ self.freeze()
+ cPickle.dump(self, outfile, 2)
+ finally:
+ outfile.close()
+
class _CallTreeFilter(object):
+ """Converter of a Stats object to input suitable for KCacheGrind.
+
+ This code is taken from http://ddaa.net/blog/python/lsprof-calltree
+ with the changes made by J.P. Calderone and Itamar applied. Note that
+ isinstance(code, str) needs to be used at times to determine if the code
+ object is actually an external code object (with a filename, etc.) or
+ a Python built-in.
+ """
def __init__(self, data):
self.data = data
@@ -130,16 +166,26 @@
code = entry.code
inlinetime = int(entry.inlinetime * 1000)
#print >> out_file, 'ob=%s' % (code.co_filename,)
- print >> out_file, 'fi=%s' % (code.co_filename,)
+ if isinstance(code, str):
+ print >> out_file, 'fi=~'
+ else:
+ print >> out_file, 'fi=%s' % (code.co_filename,)
print >> out_file, 'fn=%s' % (label(code, True),)
- print >> out_file, '%d %d' % (code.co_firstlineno, inlinetime)
+ if isinstance(code, str):
+ print >> out_file, '0 ', inlinetime
+ else:
+ print >> out_file, '%d %d' % (code.co_firstlineno, inlinetime)
# recursive calls are counted in entry.calls
if entry.calls:
calls = entry.calls
else:
calls = []
+ if isinstance(code, str):
+ lineno = 0
+ else:
+ lineno = code.co_firstlineno
for subentry in calls:
- self._subentry(code.co_firstlineno, subentry)
+ self._subentry(lineno, subentry)
print >> out_file
def _subentry(self, lineno, subentry):
@@ -148,12 +194,15 @@
totaltime = int(subentry.totaltime * 1000)
#print >> out_file, 'cob=%s' % (code.co_filename,)
print >> out_file, 'cfn=%s' % (label(code, True),)
- print >> out_file, 'cfi=%s' % (code.co_filename,)
- print >> out_file, 'calls=%d %d' % (
- subentry.callcount, code.co_firstlineno)
+ if isinstance(code, str):
+ print >> out_file, 'cfi=~'
+ print >> out_file, 'calls=%d 0' % (subentry.callcount,)
+ else:
+ print >> out_file, 'cfi=%s' % (code.co_filename,)
+ print >> out_file, 'calls=%d %d' % (
+ subentry.callcount, code.co_firstlineno)
print >> out_file, '%d %d' % (lineno, totaltime)
-
_fn2mod = {}
def label(code, calltree=False):
=== modified file 'bzrlib/tests/__init__.py'
--- a/bzrlib/tests/__init__.py 2007-06-06 23:16:55 +0000
+++ b/bzrlib/tests/__init__.py 2007-06-12 14:57:07 +0000
@@ -2308,6 +2308,7 @@
'bzrlib.tests.test_lockdir',
'bzrlib.tests.test_lockable_files',
'bzrlib.tests.test_log',
+ 'bzrlib.tests.test_lsprof',
'bzrlib.tests.test_memorytree',
'bzrlib.tests.test_merge',
'bzrlib.tests.test_merge3',
=== modified file 'bzrlib/tests/test_selftest.py'
--- a/bzrlib/tests/test_selftest.py 2007-05-24 16:12:53 +0000
+++ b/bzrlib/tests/test_selftest.py 2007-06-12 14:51:11 +0000
@@ -54,7 +54,8 @@
iter_suite_tests,
filter_suite_by_re,
sort_suite_by_re,
- test_suite
+ test_lsprof,
+ test_suite,
)
from bzrlib.tests.test_sftp_transport import TestCaseWithSFTPServer
from bzrlib.tests.TestUtil import _load_module_by_name
@@ -680,10 +681,7 @@
def test_lsprofiling(self):
"""Verbose test result prints lsprof statistics from test cases."""
- try:
- import bzrlib.lsprof
- except ImportError:
- raise TestSkipped("lsprof not installed.")
+ self.requireFeature(test_lsprof.LSProf())
result_stream = StringIO()
result = bzrlib.tests.VerboseTestResult(
unittest._WritelnDecorator(result_stream),
@@ -1195,10 +1193,7 @@
Each self.time() call is individually and separately profiled.
"""
- try:
- import bzrlib.lsprof
- except ImportError:
- raise TestSkipped("lsprof not installed.")
+ self.requireFeature(test_lsprof.LSProf())
# overrides the class member with an instance member so no cleanup
# needed.
self._gather_lsprof_in_benchmarks = True
=== modified file 'doc/developers/index.txt'
--- a/doc/developers/index.txt 2007-06-01 07:47:03 +0000
+++ b/doc/developers/index.txt 2007-06-12 14:57:07 +0000
@@ -18,3 +18,6 @@
Notes on a container format for streaming and storing Bazaar data.
+* `Profiling notes <profiling.htm>`_
+
+ Instructions on how to profile bzr code and visualize the results.
More information about the bazaar-commits
mailing list