Patchwork [1,of,6] blackbox: adds a blackbox extension

# HG changeset patch
# User Durham Goode <durham@fb.com>
# Date 1360429429 28800
# Node ID 30544b5277d09002d6cac8c363652f71bb807516
# Parent  57b7531a5705a099637f6d6bedd4de509fb2a441
blackbox: adds a blackbox extension

Adds a blackbox extension that listens to ui.log() and writes the messages to
.hg/blackbox.log. Future commits will use ui.log() to log commands, unhandled
exceptions, incoming changes, and hooks.  The extension defaults to logging
everything, but can be configured via blackbox.trackedevents to only log
certain events. Log lines are of the format:  "date time user> message"

Example log line:
2013/02/09 08:35:19 durham> 1 incoming changes - new heads: d84ced58aaa

On Sun, Feb 10, 2013 at 11:07 AM, Durham Goode <durham@fb.com> wrote:
> # HG changeset patch
> # User Durham Goode <durham@fb.com>
> # Date 1360429429 28800
> # Node ID 30544b5277d09002d6cac8c363652f71bb807516
> # Parent  57b7531a5705a099637f6d6bedd4de509fb2a441
> blackbox: adds a blackbox extension
>
> Adds a blackbox extension that listens to ui.log() and writes the messages to
> .hg/blackbox.log. Future commits will use ui.log() to log commands, unhandled
> exceptions, incoming changes, and hooks.  The extension defaults to logging
> everything, but can be configured via blackbox.trackedevents to only log
> certain events. Log lines are of the format:  "date time user> message"
>
> Example log line:
> 2013/02/09 08:35:19 durham> 1 incoming changes - new heads: d84ced58aaa
>
> diff --git a/hgext/blackbox.py b/hgext/blackbox.py
> new file mode 100644
> --- /dev/null
> +++ b/hgext/blackbox.py
> @@ -0,0 +1,68 @@
> +"""log repository events to a blackbox for debugging
> +
> +Logs event information to .hg/blackbox.log to help debug and diagnose problems.
> +The events that get logged can be configured via the blackbox.trackedevents
> +config key. Examples:
> +
> +  [blackbox]
> +  trackedevents=*
> +
> +  [blackbox]
> +  trackedevents=command,commandfinished,commandexception,exthook,pythonhook
> +
> +  [blackbox]
> +  trackedevents=incoming

Minor nit: I think the style we normally use is "option = value" and
"option = list, of, values".

Also, what about calling this "track" instead of "trackedevents"?

> +
> +"""
> +
> +from mercurial import util, cmdutil
> +from mercurial.i18n import _
> +import os, getpass, re, string
> +
> +cmdtable = {}
> +command = cmdutil.command(cmdtable)
> +testedwith='internal'
> +lastblackbox=None

There should be spaces between = here. Running check-code should catch this.

> +
> +def wrapui(ui):
> +    class blackboxui(ui.__class__):
> +        @util.propertycache
> +        def trackedevents(self):
> +            events = ui.config('blackbox', 'trackedevents', '*')
> +            return string.split(events, ',')

I think you should be using ui.configlist() here.

> +
> +        def log(self, command, msg):
> +            global lastblackbox
> +            super(blackboxui, self).log(command, msg)
> +
> +            if not '*' in self.trackedevents and \
> +               not command in self.trackedevents:
> +                return

Don't use line continuations (the backslash); group the condition in
parentheses.

> +
> +            if '_blackbox' in self.__dict__:

This seems like a weird way of checking this (it isn't the case here,
but Python objects don't always have __dict__). I think you want
util.safehasattr().

> +                blackbox = self._blackbox
> +            else:
> +                # certain ui instances exist outside the context of
> +                # a repo, so just default to the last blackbox that
> +                # was seen.
> +                blackbox = lastblackbox
> +
> +            if blackbox:
> +                date = util.datestr(None, '%Y/%m/%d %H:%M:%S')
> +                user = getpass.getuser()
> +                blackbox.write('%s %s> %s\n' % (date, user, msg))
> +                lastblackbox = blackbox
> +
> +        def setrepo(self, repo):
> +            self._blackbox = repo.opener('blackbox.log', 'a')
> +
> +    ui.__class__ = blackboxui
> +
> +def uisetup(ui):
> +    wrapui(ui)
> +
> +def reposetup(ui, repo):
> +    if not repo.local():
> +        return

I don't follow this. Can you explain why you need to bail when the
repo isn't local?

> +
> +    ui.setrepo(repo)
> _______________________________________________
> Mercurial-devel mailing list
> Mercurial-devel@selenic.com
> http://selenic.com/mailman/listinfo/mercurial-devel

Thanks for the comments.

>Also, what about calling this "track" instead of "trackedevents"?

I went through the existing config options and 'track' does seem to be
more consistent. Will do.

>There should be spaces between = here. Running check-code should catch
>this.

Check-code didn't catch this.

>> +def reposetup(ui, repo):
>> +    if not repo.local():
>> +        return
>
>I don't follow this. Can you explain why you need to bail when the
>repo isn't local?

When talking to remote repos, mercurial creates a httppeer repo as a
representation of the remote repo.  The httppeer doesn't have a .hg
directory to dump a blackbox.log in, so we don't do the blackbox setup for
those kinds of repos.  I'll add a comment explaining that.

On Sun, Feb 10, 2013 at 12:09:45PM +0000, Brodie Rao wrote:
> > +
> > +            if '_blackbox' in self.__dict__:
> 
> This seems like a weird way of checking this (it isn't the case here,
> but Python objects don't always have __dict__). I think you want
> util.safehasattr().

Has Brodie said: DON'T

What you want to check is the existence of 'self._blackbox'. use `util.safehasattr()` (python on is broken)

In the very rare case where you really want to check dict (existence in the local object namespace) use `vars`

"if '_blockbox' in vars(self)"