Rev 2732: (robertc) Add -Devil flag to highlight the use of problematic API calls. in file:///home/pqm/archives/thelove/bzr/%2Btrunk/
Canonical.com Patch Queue Manager
pqm at pqm.ubuntu.com
Mon Aug 20 10:43:10 BST 2007
At file:///home/pqm/archives/thelove/bzr/%2Btrunk/
------------------------------------------------------------
revno: 2732
revision-id: pqm at pqm.ubuntu.com-20070820094305-9oosrencb83z0a6x
parent: pqm at pqm.ubuntu.com-20070820085715-696xuo3cm3iyq5yj
parent: robertc at robertcollins.net-20070820034340-am05707e05l1nth5
committer: Canonical.com Patch Queue Manager <pqm at pqm.ubuntu.com>
branch nick: +trunk
timestamp: Mon 2007-08-20 10:43:05 +0100
message:
(robertc) Add -Devil flag to highlight the use of problematic API calls.
modified:
NEWS NEWS-20050323055033-4e00b5db738777ff
bzrlib/debug.py debug.py-20061102062349-vdhrw9qdpck8cl35-1
bzrlib/tests/__init__.py selftest.py-20050531073622-8d0e3c8845c97a64
bzrlib/tests/test_trace.py testtrace.py-20051110225523-a21117fc7a07eeff
bzrlib/trace.py trace.py-20050309040759-c8ed824bdcd4748a
doc/developers/performance-contributing.txt performancecontribut-20070621063612-ac4zhhagjzkr21qp-1
------------------------------------------------------------
revno: 2725.1.1
merged: robertc at robertcollins.net-20070820034340-am05707e05l1nth5
parent: pqm at pqm.ubuntu.com-20070817192843-0jaoxooskia72irk
committer: Robert Collins <robertc at robertcollins.net>
branch nick: devil
timestamp: Mon 2007-08-20 13:43:40 +1000
message:
Add -Devil flag to highlight the use of problematic API calls.
=== modified file 'NEWS'
--- a/NEWS 2007-08-20 05:27:07 +0000
+++ b/NEWS 2007-08-20 09:43:05 +0000
@@ -39,11 +39,15 @@
* ``Branch.append_revision`` is removed altogether; please use
``Branch.set_last_revision_info`` instead. (Martin Pool)
- aPI CHANGES:
-
* ``Transport.should_cache`` has been removed. It was not called in the
previous release. (Martin Pool)
+ INTERNALS:
+
+ * New trace function ``mutter_callsite`` will print out a subset of the
+ stack to the log, which can be useful for gathering debug details.
+ (Robert Collins)
+
bzr 0.90rc1 2007-08-14
BUGFIXES:
=== modified file 'bzrlib/debug.py'
--- a/bzrlib/debug.py 2007-07-09 04:31:30 +0000
+++ b/bzrlib/debug.py 2007-08-20 03:43:40 +0000
@@ -21,7 +21,8 @@
These are set with eg ``-Dlock`` on the bzr command line.
Options include:
-
+
+ * evil - capture call sites that do expensive or badly-scaling operations.
* error - show stack traces for all top level exceptions
* hooks
* hpss - trace smart protocol requests and responses
=== modified file 'bzrlib/tests/__init__.py'
--- a/bzrlib/tests/__init__.py 2007-08-17 05:08:52 +0000
+++ b/bzrlib/tests/__init__.py 2007-08-20 03:43:40 +0000
@@ -1202,9 +1202,14 @@
mutter(*args)
def _get_log(self, keep_log_file=False):
- """Return as a string the log for this test. If the file is still
- on disk and keep_log_file=False, delete the log file and store the
- content in self._log_contents."""
+ """Get the log from bzrlib.trace calls from this test.
+
+ :param keep_log_file: When True, if the log is still a file on disk
+ leave it as a file on disk. When False, if the log is still a file
+ on disk, the log file is deleted and the log preserved as
+ self._log_contents.
+ :return: A string containing the log.
+ """
# flush the log file, to get all content
import bzrlib.trace
bzrlib.trace._trace_file.flush()
=== modified file 'bzrlib/tests/test_trace.py'
--- a/bzrlib/tests/test_trace.py 2006-11-17 05:53:17 +0000
+++ b/bzrlib/tests/test_trace.py 2007-08-20 03:43:40 +0000
@@ -27,7 +27,7 @@
errors,
)
from bzrlib.tests import TestCaseInTempDir, TestCase
-from bzrlib.trace import mutter, report_exception
+from bzrlib.trace import mutter, mutter_callsite, report_exception
def _format_exception():
@@ -113,6 +113,30 @@
else:
self.fail("expected error not raised")
+ def test_mutter_callsite_1(self):
+ """mutter_callsite can capture 1 level of stack frame."""
+ mutter_callsite(1, "foo %s", "a string")
+ log = self._get_log(keep_log_file=True)
+ # begin with the message
+ self.assertStartsWith(log, 'foo a string\nCalled from:\n')
+ # should show two frame: this frame and the one above
+ self.assertContainsRe(log,
+ 'test_trace\.py", line \d+, in test_mutter_callsite_1\n')
+ # this frame should be the final one
+ self.assertEndsWith(log, ' "a string")\n')
+
+ def test_mutter_callsite_2(self):
+ """mutter_callsite can capture 2 levels of stack frame."""
+ mutter_callsite(2, "foo %s", "a string")
+ log = self._get_log(keep_log_file=True)
+ # begin with the message
+ self.assertStartsWith(log, 'foo a string\nCalled from:\n')
+ # should show two frame: this frame and the one above
+ self.assertContainsRe(log,
+ 'test_trace.py", line \d+, in test_mutter_callsite_2\n')
+ # this frame should be the final one
+ self.assertEndsWith(log, ' "a string")\n')
+
def test_mutter_never_fails(self):
# Even if the decode/encode stage fails, mutter should not
# raise an exception
@@ -123,3 +147,4 @@
self.assertContainsRe(log, 'Writing a greek mu')
self.assertContainsRe(log, "But fails in an ascii string")
self.assertContainsRe(log, u"ascii argument: \xb5")
+
=== modified file 'bzrlib/trace.py'
--- a/bzrlib/trace.py 2007-08-15 04:33:34 +0000
+++ b/bzrlib/trace.py 2007-08-20 03:43:40 +0000
@@ -56,8 +56,10 @@
from bzrlib.lazy_import import lazy_import
lazy_import(globals(), """
+from cStringIO import StringIO
import errno
import logging
+import traceback
""")
import bzrlib
@@ -122,6 +124,21 @@
#_trace_file.flush()
+def mutter_callsite(stacklevel, fmt, *args):
+ """Perform a mutter of fmt and args, logging the call trace.
+
+ :param stacklevel: The number of frames to show. None will show all
+ frames.
+ :param fmt: The format string to pass to mutter.
+ :param args: A list of substitution variables.
+ """
+ outf = StringIO()
+ traceback.print_stack(limit=stacklevel + 1, file=outf)
+ formatted_lines = outf.getvalue().splitlines()
+ formatted_stack = '\n'.join(formatted_lines[:-2])
+ mutter(fmt + "\nCalled from:\n%s", *(args + (formatted_stack,)))
+
+
def _rollover_trace_maybe(trace_fname):
import stat
try:
=== modified file 'doc/developers/performance-contributing.txt'
--- a/doc/developers/performance-contributing.txt 2007-06-21 06:41:07 +0000
+++ b/doc/developers/performance-contributing.txt 2007-08-20 03:43:40 +0000
@@ -10,6 +10,13 @@
changes. In general, pick a BLUE node from performance.png which has nothing
pointing at it that is also BLUE, and start working on that.
+Adhoc performance work can also be done. One useful tool is the 'evil' debug
+flag. For instance running ``bzr -Devil commit -m 'test'`` will log a backtrace
+to the bzr log file for every method call which triggers a slow or non-scalable
+part of the bzr library. So checking that a given command with ``-Devil`` has
+no backtraces logged to the log file is a good way to find problem function
+calls that might be nested deep in the code base.
+
Status
------
More information about the bazaar-commits
mailing list