# HG changeset patch # User Boris Feld <boris.f...@octobus.net> # Date 1515753663 0 # Fri Jan 12 10:41:03 2018 +0000 # Node ID 2d1a4bbddd7e4075b0e082cabf84d901f5b92b5b # Parent 6d0599c2fe114d927f2d37fd5a22e061843c6974 # EXP-Topic exchangedebug # Available At https://bitbucket.org/octobus/mercurial-devel/ # hg pull https://bitbucket.org/octobus/mercurial-devel/ -r 2d1a4bbddd7e httppeer: add support for tracing all http request made by the peer
This changeset introduces a new 'devel.debug.peer-request' config. When set to True, debug message about request made by peer will be issued. This help to understand what actually happens during an exchange and tracks source of performance loss. This changeset implement support for http peer only. diff --git a/mercurial/configitems.py b/mercurial/configitems.py --- a/mercurial/configitems.py +++ b/mercurial/configitems.py @@ -362,6 +362,9 @@ coreconfigitem('devel', 'user.obsmarker' coreconfigitem('devel', 'warn-config-unknown', default=None, ) +coreconfigitem('devel', 'debug.peer-request', + default=False, +) coreconfigitem('diff', 'nodates', default=False, ) diff --git a/mercurial/httppeer.py b/mercurial/httppeer.py --- a/mercurial/httppeer.py +++ b/mercurial/httppeer.py @@ -162,7 +162,38 @@ class httppeer(wireproto.wirepeer): getattr(h, "close_all", lambda: None)() def _openurl(self, req): - return self._urlopener.open(req) + if self._ui.configbool('devel', 'debug.peer-request'): + dbg = self._ui.debug + line = 'devel-peer-request: %s\n' + dbg(line % '%s %s' % (req.get_method(), req.get_full_url())) + hgargssize = None + + for header, value in sorted(req.header_items()): + if header.startswith('X-hgarg-'): + if hgargssize is None: + hgargssize = 0 + hgargssize += len(value) + else: + dbg(line % ' %s %s' % (header, value)) + + if hgargssize is not None: + dbg(line % ' %d bytes of commands arguments in headers' + % hgargssize) + + if req.has_data(): + data = req.get_data() + length = getattr(data, 'length', None) + if length is None: + length = len(data) + dbg(line % ' %d bytes of data' % length) + + start = util.timer() + + ret = self._urlopener.open(req) + if self._ui.configbool('devel', 'debug.peer-request'): + dbg(line % ' finished in %.4f seconds (%s)' + % (util.timer() - start, ret.code)) + return ret # Begin of _basepeer interface. diff --git a/tests/test-http.t b/tests/test-http.t --- a/tests/test-http.t +++ b/tests/test-http.t @@ -248,27 +248,57 @@ test http authentication remote: adding file changes remote: added 1 changesets with 1 changes to 1 files $ hg rollback -q - $ hg -R dest push http://user:pass@localhost:$HGPORT2/ --debug + $ hg -R dest push http://user:pass@localhost:$HGPORT2/ --debug --config devel.debug.peer-request=yes pushing to http://user:***@localhost:$HGPORT2/ using http://localhost:$HGPORT2/ http auth: user user, password **** sending capabilities command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=capabilities + devel-peer-request: finished in *.???? seconds (200) (glob) query 1; heads sending batch command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=batch + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 68 bytes of commands arguments in headers + devel-peer-request: finished in *.???? seconds (200) (glob) searching for changes all remote heads known locally preparing listkeys for "phases" sending listkeys command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=listkeys + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 16 bytes of commands arguments in headers http auth: user user, password **** + devel-peer-request: finished in *.???? seconds (200) (glob) received listkey for "phases": 58 bytes checking for updated bookmarks preparing listkeys for "bookmarks" sending listkeys command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=listkeys + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 19 bytes of commands arguments in headers + devel-peer-request: finished in *.???? seconds (200) (glob) received listkey for "bookmarks": 0 bytes sending branchmap command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=branchmap + devel-peer-request: Vary X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: finished in *.???? seconds (200) (glob) sending branchmap command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=branchmap + devel-peer-request: Vary X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: finished in *.???? seconds (200) (glob) preparing listkeys for "bookmarks" sending listkeys command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=listkeys + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 19 bytes of commands arguments in headers + devel-peer-request: finished in *.???? seconds (200) (glob) received listkey for "bookmarks": 0 bytes 1 changesets found list of changesets: @@ -281,6 +311,14 @@ test http authentication bundle2-output-part: "phase-heads" 24 bytes payload sending unbundle command sending 986 bytes + devel-peer-request: POST http://localhost:$HGPORT2/?cmd=unbundle + devel-peer-request: Content-length 986 + devel-peer-request: Content-type application/mercurial-0.1 + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 16 bytes of commands arguments in headers + devel-peer-request: 986 bytes of data + devel-peer-request: finished in *.???? seconds (200) (glob) bundle2-input-bundle: no-transaction bundle2-input-part: "reply:changegroup" (advisory) (params: 0 advisory) supported bundle2-input-part: "output" (advisory) (params: 0 advisory) supported @@ -293,6 +331,11 @@ test http authentication bundle2-input-bundle: 2 parts total preparing listkeys for "phases" sending listkeys command + devel-peer-request: GET http://localhost:$HGPORT2/?cmd=listkeys + devel-peer-request: Vary X-HgArg-1,X-HgProto-1 + devel-peer-request: X-hgproto-1 0.1 0.2 comp=$USUAL_COMPRESSIONS$ + devel-peer-request: 16 bytes of commands arguments in headers + devel-peer-request: finished in *.???? seconds (200) (glob) received listkey for "phases": 15 bytes $ hg rollback -q _______________________________________________ Mercurial-devel mailing list Mercurial-devel@mercurial-scm.org https://www.mercurial-scm.org/mailman/listinfo/mercurial-devel