From patchwork Tue Nov 14 06:26:20 2017
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: D1391: bundle2: inline debug logging
From: phabricator <phabricator@mercurial-scm.org>
X-Patchwork-Id: 25550
Message-Id: <differential-rev-PHID-DREV-phet32j2sacqkbrbxzcy-req@phab.mercurial-scm.org>
To: mercurial-devel@mercurial-scm.org
Date: Tue, 14 Nov 2017 06:26:20 +0000

indygreg created this revision.
Herald added a subscriber: mercurial-devel.
Herald added a reviewer: hg-reviewers.

REVISION SUMMARY
  Profiling revealed that repeated calls to indebug() were
  consuming a fair amount of CPU during bundle2 reading, with
  most of the time spent in ui.configbool().
  
  Inlining indebug() and avoiding extra attribute lookups speeds
  things up substantially. Using `hg perfbundleread` with a Firefox
  bundle:
  
  ! read(8k)
  ! wall 0.679730 comb 0.680000 user 0.140000 sys 0.540000 (best of 15)
  ! read(16k)
  ! wall 0.577228 comb 0.570000 user 0.080000 sys 0.490000 (best of 17)
  ! read(32k)
  ! wall 0.516060 comb 0.520000 user 0.040000 sys 0.480000 (best of 20)
  ! read(128k)
  ! wall 0.496378 comb 0.490000 user 0.010000 sys 0.480000 (best of 20)
  ! bundle2 iterparts()
  ! wall 6.983756 comb 6.980000 user 6.220000 sys 0.760000 (best of 3)
  ! wall 3.460903 comb 3.460000 user 2.760000 sys 0.700000 (best of 3)
  ! bundle2 iterparts() seekable
  ! wall 8.132131 comb 8.110000 user 7.160000 sys 0.950000 (best of 3)
  ! wall 4.312722 comb 4.310000 user 3.480000 sys 0.830000 (best of 3)
  ! bundle2 part seek()
  ! wall 10.860942 comb 10.840000 user 7.790000 sys 3.050000 (best of 3)
  ! wall 6.754764 comb 6.740000 user 3.970000 sys 2.770000 (best of 3)
  ! bundle2 part read(8k)
  ! wall 7.258035 comb 7.260000 user 6.470000 sys 0.790000 (best of 3)
  ! wall 3.668004 comb 3.660000 user 2.960000 sys 0.700000 (best of 3)
  ! bundle2 part read(16k)
  ! wall 7.099891 comb 7.080000 user 6.310000 sys 0.770000 (best of 3)
  ! wall 3.489196 comb 3.480000 user 2.750000 sys 0.730000 (best of 3)
  ! bundle2 part read(32k)
  ! wall 6.964685 comb 6.950000 user 6.130000 sys 0.820000 (best of 3)
  ! wall 3.388569 comb 3.380000 user 2.640000 sys 0.740000 (best of 3)
  ! bundle2 part read(128k)
  ! wall 6.852867 comb 6.850000 user 6.060000 sys 0.790000 (best of 3)
  ! wall 3.276415 comb 3.270000 user 2.560000 sys 0.710000 (best of 4)

REPOSITORY
  rHG Mercurial

REVISION DETAIL
  https://phab.mercurial-scm.org/D1391

AFFECTED FILES
  mercurial/bundle2.py

CHANGE DETAILS




To: indygreg, #hg-reviewers
Cc: mercurial-devel

diff --git a/mercurial/bundle2.py b/mercurial/bundle2.py
--- a/mercurial/bundle2.py
+++ b/mercurial/bundle2.py
@@ -1193,6 +1193,9 @@
     Part payload data consists of framed chunks. This function takes
     a file handle and emits those chunks.
     """
+    dolog = ui.configbool('devel', 'bundle2.debug')
+    debug = ui.debug
+
     headersize = struct.calcsize(_fpayloadsize)
     readexactly = changegroup.readexactly
 
@@ -1211,7 +1214,10 @@
                 'negative payload chunk size: %s' % chunksize)
 
         chunksize = _unpack(_fpayloadsize, readexactly(fh, headersize))[0]
-        indebug(ui, 'payload chunk size: %i' % chunksize)
+
+        # indebug() inlined for performance.
+        if dolog:
+            debug('bundle2-input: payload chunk size: %i\n' % chunksize)
 
 class unbundlepart(unpackermixin):
     """a bundle part read from a bundle"""