( )⚙ D4344 tracing: new module to make tracing events in hg easier

This is an archive of the discontinued Mercurial Phabricator instance.

Differential D4344

tracing: new module to make tracing events in hg easier
ClosedPublic

Authored by durin42 on Aug 21 2018, 5:39 PM.

Details

Reviewers
None
Group Reviewers
hg-reviewers
Commits
rHG284440041141: tracing: new module to make tracing events in hg easier
Summary

This lives in hgdemandimport because I want to instrument a bunch of
low-level stuff including the bare hg script and demandimport, so it
can't live at a higher layer.

Diff Detail

Repository
rHG Mercurial
Lint
Lint Skipped
Unit
Unit Tests Skipped

Event Timeline

durin42 created this revision.Aug 21 2018, 5:39 PM
indygreg added a subscriber: indygreg.Aug 24 2018, 1:02 PM
indygreg added inline comments.
hgdemandimport/tracing.py
31–34

Per my comment in D4342, I think we should consider recording the timing from here so times aren't skewed due to the presence of pipe I/O. That will introduce some overhead in the traced process. But such is the price to be paid for accurate time reporting, I suppose.

Closed by commit rHG284440041141: tracing: new module to make tracing events in hg easier (authored by durin42). · Explain WhyAug 24 2018, 1:14 PM
This revision was automatically updated to reflect the committed changes.
durin42 added a comment.Aug 28 2018, 1:52 PM

Per my comment in https://phab.mercurial-scm.org/D4342 https://phab.mercurial-scm.org/D4342, I think we should consider recording the timing from here so times aren't skewed due to the presence of pipe I/O. That will introduce some overhead in the traced process. But such is the price to be paid for accurate time reporting, I suppose.

My thinking on that was to avoid the syscall overhead for getting timestamps in the main hg process, which we’ve seen be a huge drag on performance. I couldn’t think of anything cheaper than a single string interpolation and a write to a named pipe, so that’s what we’ve got for now - we can always pursue more in the future if we want, but I want this tracing to be cheap enough that I could plausibly turn it on for 1% of invocations )or whatever) and not have users notice.

Revision Contents
Changeset List

PathPackages
AMhgdemandimport/tracing.py (34 lines)

Diff 10494

hgdemandimport/tracing.py

  • This file was added.
# Support code for event tracing in Mercurial. Lives in demandimport
# so it can also be used in demandimport.
#
# Copyright 2018 Google LLC.
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version.
from __future__ import absolute_import
import contextlib
import os
_pipe = None
_checked = False
@contextlib.contextmanager
def log(whencefmt, *whenceargs):
global _pipe, _session, _checked
if _pipe is None:
if _checked:
yield
return
_checked = True
if 'HGCATAPULTSERVERPIPE' not in os.environ:
yield
return
_pipe = open(os.environ['HGCATAPULTSERVERPIPE'], 'w', 1)
_session = os.environ.get('HGCATAPULTSESSION', 'none')
whence = whencefmt % whenceargs
try:
_pipe.write('START %s %s\n' % (_session, whence))
yield
finally:
_pipe.write('END %s %s\n' % (_session, whence))
indygregUnsubmitted
Not Done

Per my comment in D4342, I think we should consider recording the timing from here so times aren't skewed due to the presence of pipe I/O. That will introduce some overhead in the traced process. But such is the price to be paid for accurate time reporting, I suppose.

indygreg: Per my comment in D4342, I think we should consider recording the timing from here so times…