Rev 110: Move a lot of history_db tracing into mutter/debug_flag code. in http://bzr.arbash-meinel.com/branches/bzr/history_db/trunk

John Arbash Meinel john at arbash-meinel.com
Thu Apr 22 22:27:36 BST 2010


At http://bzr.arbash-meinel.com/branches/bzr/history_db/trunk

------------------------------------------------------------
revno: 110
revision-id: john at arbash-meinel.com-20100422212721-0ztw9wz7ohdg8afz
parent: john at arbash-meinel.com-20100422192953-kbpqw0kwl4ifhjhx
committer: John Arbash Meinel <john at arbash-meinel.com>
branch nick: trunk
timestamp: Thu 2010-04-22 16:27:21 -0500
message:
  Move a lot of history_db tracing into mutter/debug_flag code.
-------------- next part --------------
=== modified file '__init__.py'
--- a/__init__.py	2010-04-22 19:29:53 +0000
+++ b/__init__.py	2010-04-22 21:27:21 +0000
@@ -441,10 +441,10 @@
     merge_sorted = self._filter_non_ancestors(iter(merge_sorted))
     t2 = time.clock()
     if 'history_db' in debug.debug_flags:
+        import pprint
         trace.note('history_db iter_merge took %.3fs (%.3fs query)'
                    % (t2-t0, t1-t0))
-    import pprint
-    trace.mutter('Stats:\n%s' % (pprint.pformat(dict(query._stats)),))
+        trace.mutter('Stats:\n%s' % (pprint.pformat(dict(query._stats)),))
     if direction == 'reverse':
         return merge_sorted
     elif direction == 'forward':
@@ -457,20 +457,23 @@
     """See Branch._do_revision_id_to_dotted_revno"""
     revno = self._partial_revision_id_to_revno_cache.get(revision_id, None)
     if revno is not None:
-        trace.note('history_db rev=>dotted cached %s' % (revno,))
+        if 'history_db' in debug.debug_flags:
+            trace.note('history_db rev=>dotted cached %s' % (revno,))
         return revno
     t0 = time.clock()
     query = _get_querier(self)
     if query is None:
-        trace.mutter('history_db falling back to original'
-                     'revision_id => dotted_revno')
+        if 'history_db' in debug.debug_flags:
+            trace.mutter('history_db falling back to original'
+                         'revision_id => dotted_revno')
         return _orig_do_rev_id_to_dotted(self, revision_id)
     t1 = time.clock()
     revision_id_map = query.get_dotted_revno_range_multi([revision_id])
     t2 = time.clock()
-    trace.note('history_db rev=>dotted %s took %.3fs, %.3fs to init,'
-               ' %.3fs to query' % (revision_id_map.values(),
-                                    t2-t0, t1-t0, t2-t1))
+    if 'history_db' in debug.debug_flags:
+        trace.note('history_db rev=>dotted %s took %.3fs, %.3fs to init,'
+                   ' %.3fs to query' % (revision_id_map.values(),
+                                        t2-t0, t1-t0, t2-t1))
     self._partial_revision_id_to_revno_cache.update(revision_id_map)
 
     if revision_id not in revision_id_map:
@@ -486,14 +489,16 @@
     t0 = time.clock()
     query = _get_querier(self)
     if query is None:
-        trace.mutter('history_db falling back to original'
+        if 'history_db' in debug.debug_flags:
+            trace.mutter('history_db falling back to original'
                      'dotted_revno => revision_id, "history_db_path" not set')
         return _orig_do_dotted_revno(self, revno)
     t1 = time.clock()
     revno_map = query.get_revision_ids([revno])
     t2 = time.clock()
-    trace.note('history_db dotted=>rev took %.3fs, %.3fs to init,'
-               ' %.3fs to query' % (t2-t0, t1-t0, t2-t1))
+    if 'history_db' in debug.debug_flags:
+        trace.note('history_db dotted=>rev took %.3fs, %.3fs to init,'
+                   ' %.3fs to query' % (t2-t0, t1-t0, t2-t1))
     self._partial_revision_id_to_revno_cache.update(
         [(r_id, r_no) for r_no, r_id in revno_map.iteritems()])
                
@@ -514,8 +519,9 @@
     history_db_path = _get_history_db_path(params.branch)
     t1 = time.clock()
     if history_db_path is None:
-        trace.mutter('Note updating history-db, "history_db_path"'
-                     ' not configured')
+        if 'history_db' in debug.debug_flags:
+            trace.mutter('Note updating history-db, "history_db_path"'
+                         ' not configured')
         return
     importer = _mod_history_db.Importer(history_db_path, params.branch,
                                         tip_revision_id=params.new_revid,
@@ -525,11 +531,15 @@
     t3 = time.clock()
     importer.build_mainline_cache()
     t4 = time.clock()
-    trace.note('history_db post-change-hook took %.3fs'
-               ' (%.3fs to get_config, %.3fs to init, %.3fs to import)'
-               % (t4-t0, t1-t0, t2-t1, t3-t2))
-    trace.mutter('Stats:\n%s' % (pprint.pformat(dict(importer._stats)),))
-
+    if 'history_db' in debug.debug_flags:
+        info = trace.note
+    else:
+        info = trace.mutter
+    info('history_db post-change-hook took %.3fs'
+         ' (%.3fs to get_config, %.3fs to init, %.3fs to import)'
+         % (t4-t0, t1-t0, t2-t1, t3-t2))
+    trace.mutter('Stats:\n%s'
+                 % (pprint.pformat(dict(importer._stats)),))
 
 
 def _register_history_db_hooks():

=== modified file 'history_db.py'
--- a/history_db.py	2010-04-21 22:23:35 +0000
+++ b/history_db.py	2010-04-22 21:27:21 +0000
@@ -25,6 +25,7 @@
 import time
 
 from bzrlib import (
+    debug,
     errors,
     lru_cache,
     revision,
@@ -126,7 +127,8 @@
     def _ensure_schema(self):
         if not schema.is_initialized(self._db_conn, dbapi2.OperationalError):
             schema.create_sqlite_db(self._db_conn)
-            trace.note('Initialized database')
+            if 'history_db' in debug.debug_flags:
+                trace.note('history_db initialized database')
             # We know we can't do this incrementally, because nothing has
             # existed before...
             #self._incremental = False
@@ -1044,14 +1046,6 @@
                 self._stats['step mainline to-latest NULL'] += 1
             self._step_mainline()
             step_count += 1
-        return
-        if step_count > 10:
-            end_info = ''
-            if start_point is not None:
-                end_info = '%s' % (tuple(self._imported_dotted_revno[start_point][0]),)
-            trace.note('stepped %d for %d, started at %s %s, ended at %s for %s'
-                       % (step_count, base_revno, start_point,
-                          end_info, self._imported_mainline_id, found))
 
     def _pop_node(self):
         """Move the last node from the _depth_first_stack to _scheduled_stack.
@@ -1229,8 +1223,10 @@
                             incremental=True)
         importer.do_import()
         tdelta = time.time() - t
-        trace.note('imported %d nodes on-the-fly in %.3fs'
-                   % (importer._stats.get('total_nodes_inserted', 0), tdelta))
+        if 'history_db' in debug.debug_flags:
+            trace.note('imported %d nodes on-the-fly in %.3fs'
+                       % (importer._stats.get('total_nodes_inserted', 0),
+                          tdelta))
         self._db_conn = importer._db_conn
         self._cursor = importer._cursor
         self._branch_tip_db_id = self._get_db_id(self._branch_tip_rev_id)



More information about the bazaar-commits mailing list