This is an archive of the discontinued Mercurial Phabricator instance.

Differential D1391

bundle2: inline debug logging
ClosedPublic

Authored by indygreg on Nov 14 2017, 1:26 AM.

Details

Reviewers
durin42
Group Reviewers
hg-reviewers
Commits
rHG589eed45a452: bundle2: inline debug logging
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)

Diff Detail

Repository
rHG Mercurial
Lint
Automatic diff as part of commit; lint not applicable.
Unit
Automatic diff as part of commit; unit tests not applicable.

Event Timeline

indygreg created this revision.Nov 14 2017, 1:26 AM
durin42 accepted this revision.Nov 20 2017, 6:42 PM
This revision is now accepted and ready to land.Nov 20 2017, 6:42 PM
Closed by commit rHG589eed45a452: bundle2: inline debug logging (authored by indygreg). · Explain WhyNov 20 2017, 6:50 PM
This revision was automatically updated to reflect the committed changes.

Revision Contents
Changeset List

PathPackages
Mmercurial/bundle2.py (8 lines)

Diff 3695

mercurial/bundle2.py

raise TransactionUnavailable('no repo access from stream interruption') raise TransactionUnavailable('no repo access from stream interruption')
def decodepayloadchunks(ui, fh): def decodepayloadchunks(ui, fh):
"""Reads bundle2 part payload data into chunks. """Reads bundle2 part payload data into chunks.
Part payload data consists of framed chunks. This function takes Part payload data consists of framed chunks. This function takes
a file handle and emits those chunks. a file handle and emits those chunks.
""" """
dolog = ui.configbool('devel', 'bundle2.debug')
debug = ui.debug
headersize = struct.calcsize(_fpayloadsize) headersize = struct.calcsize(_fpayloadsize)
readexactly = changegroup.readexactly readexactly = changegroup.readexactly
chunksize = _unpack(_fpayloadsize, readexactly(fh, headersize))[0] chunksize = _unpack(_fpayloadsize, readexactly(fh, headersize))[0]
indebug(ui, 'payload chunk size: %i' % chunksize) indebug(ui, 'payload chunk size: %i' % chunksize)
while chunksize: while chunksize:
if chunksize >= 0: if chunksize >= 0:
yield readexactly(fh, chunksize) yield readexactly(fh, chunksize)
elif chunksize == flaginterrupt: elif chunksize == flaginterrupt:
# Interrupt "signal" detected. The regular stream is interrupted # Interrupt "signal" detected. The regular stream is interrupted
# and a bundle2 part follows. Consume it. # and a bundle2 part follows. Consume it.
interrupthandler(ui, fh)() interrupthandler(ui, fh)()
else: else:
raise error.BundleValueError( raise error.BundleValueError(
'negative payload chunk size: %s' % chunksize) 'negative payload chunk size: %s' % chunksize)
chunksize = _unpack(_fpayloadsize, readexactly(fh, headersize))[0] 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): class unbundlepart(unpackermixin):
"""a bundle part read from a bundle""" """a bundle part read from a bundle"""
def __init__(self, ui, header, fp): def __init__(self, ui, header, fp):
super(unbundlepart, self).__init__(fp) super(unbundlepart, self).__init__(fp)
self._seekable = (util.safehasattr(fp, 'seek') and self._seekable = (util.safehasattr(fp, 'seek') and
util.safehasattr(fp, 'tell')) util.safehasattr(fp, 'tell'))