Show More
@@ -1,115 +1,115 b'' | |||
|
1 | 1 | # blackbox.py - log repository events to a file for post-mortem debugging |
|
2 | 2 | # |
|
3 | 3 | # Copyright 2010 Nicolas Dumazet |
|
4 | 4 | # Copyright 2013 Facebook, Inc. |
|
5 | 5 | # |
|
6 | 6 | # This software may be used and distributed according to the terms of the |
|
7 | 7 | # GNU General Public License version 2 or any later version. |
|
8 | 8 | |
|
9 | 9 | """log repository events to a blackbox for debugging |
|
10 | 10 | |
|
11 | 11 | Logs event information to .hg/blackbox.log to help debug and diagnose problems. |
|
12 | 12 | The events that get logged can be configured via the blackbox.track config key. |
|
13 | 13 | Examples: |
|
14 | 14 | |
|
15 | 15 | [blackbox] |
|
16 | 16 | track = * |
|
17 | 17 | |
|
18 | 18 | [blackbox] |
|
19 | 19 | track = command, commandfinish, commandexception, exthook, pythonhook |
|
20 | 20 | |
|
21 | 21 | [blackbox] |
|
22 | 22 | track = incoming |
|
23 | 23 | |
|
24 | 24 | """ |
|
25 | 25 | |
|
26 | 26 | from mercurial import util, cmdutil |
|
27 | 27 | from mercurial.i18n import _ |
|
28 |
import os, |
|
|
28 | import os, re | |
|
29 | 29 | |
|
30 | 30 | cmdtable = {} |
|
31 | 31 | command = cmdutil.command(cmdtable) |
|
32 | 32 | testedwith = 'internal' |
|
33 | 33 | lastblackbox = None |
|
34 | 34 | |
|
35 | 35 | def wrapui(ui): |
|
36 | 36 | class blackboxui(ui.__class__): |
|
37 | 37 | @util.propertycache |
|
38 | 38 | def track(self): |
|
39 | 39 | return ui.configlist('blackbox', 'track', ['*']) |
|
40 | 40 | |
|
41 | 41 | def log(self, event, *msg, **opts): |
|
42 | 42 | global lastblackbox |
|
43 | 43 | super(blackboxui, self).log(event, *msg, **opts) |
|
44 | 44 | |
|
45 | 45 | if not '*' in self.track and not event in self.track: |
|
46 | 46 | return |
|
47 | 47 | |
|
48 | 48 | if util.safehasattr(self, '_blackbox'): |
|
49 | 49 | blackbox = self._blackbox |
|
50 | 50 | else: |
|
51 | 51 | # certain ui instances exist outside the context of |
|
52 | 52 | # a repo, so just default to the last blackbox that |
|
53 | 53 | # was seen. |
|
54 | 54 | blackbox = lastblackbox |
|
55 | 55 | |
|
56 | 56 | if blackbox: |
|
57 | 57 | date = util.datestr(None, '%Y/%m/%d %H:%M:%S') |
|
58 |
user = |
|
|
58 | user = util.getuser() | |
|
59 | 59 | formattedmsg = msg[0] % msg[1:] |
|
60 | 60 | try: |
|
61 | 61 | blackbox.write('%s %s> %s' % (date, user, formattedmsg)) |
|
62 | 62 | except IOError, err: |
|
63 | 63 | self.debug('warning: cannot write to blackbox.log: %s\n' % |
|
64 | 64 | err.strerror) |
|
65 | 65 | lastblackbox = blackbox |
|
66 | 66 | |
|
67 | 67 | def setrepo(self, repo): |
|
68 | 68 | try: |
|
69 | 69 | self._blackbox = repo.opener('blackbox.log', 'a') |
|
70 | 70 | except IOError, err: |
|
71 | 71 | self.debug('warning: cannot write to blackbox.log: %s\n' % |
|
72 | 72 | err.strerror) |
|
73 | 73 | self._blackbox = None |
|
74 | 74 | |
|
75 | 75 | ui.__class__ = blackboxui |
|
76 | 76 | |
|
77 | 77 | def uisetup(ui): |
|
78 | 78 | wrapui(ui) |
|
79 | 79 | |
|
80 | 80 | def reposetup(ui, repo): |
|
81 | 81 | # During 'hg pull' a httppeer repo is created to represent the remote repo. |
|
82 | 82 | # It doesn't have a .hg directory to put a blackbox in, so we don't do |
|
83 | 83 | # the blackbox setup for it. |
|
84 | 84 | if not repo.local(): |
|
85 | 85 | return |
|
86 | 86 | |
|
87 | 87 | ui.setrepo(repo) |
|
88 | 88 | |
|
89 | 89 | @command('^blackbox', |
|
90 | 90 | [('l', 'limit', 10, _('the number of events to show')), |
|
91 | 91 | ], |
|
92 | 92 | _('hg blackbox [OPTION]...')) |
|
93 | 93 | def blackbox(ui, repo, *revs, **opts): |
|
94 | 94 | '''view the recent repository events |
|
95 | 95 | ''' |
|
96 | 96 | |
|
97 | 97 | if not os.path.exists(repo.join('blackbox.log')): |
|
98 | 98 | return |
|
99 | 99 | |
|
100 | 100 | limit = opts.get('limit') |
|
101 | 101 | blackbox = repo.opener('blackbox.log', 'r') |
|
102 | 102 | lines = blackbox.read().split('\n') |
|
103 | 103 | |
|
104 | 104 | count = 0 |
|
105 | 105 | output = [] |
|
106 | 106 | for line in reversed(lines): |
|
107 | 107 | if count >= limit: |
|
108 | 108 | break |
|
109 | 109 | |
|
110 | 110 | # count the commands by matching lines like: 2013/01/23 19:13:36 root> |
|
111 | 111 | if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line): |
|
112 | 112 | count += 1 |
|
113 | 113 | output.append(line) |
|
114 | 114 | |
|
115 | 115 | ui.status('\n'.join(reversed(output))) |
@@ -1,136 +1,135 b'' | |||
|
1 | 1 | setup |
|
2 | 2 | $ cat > mock.py <<EOF |
|
3 | 3 | > from mercurial import util |
|
4 | > import getpass | |
|
5 | 4 | > |
|
6 | 5 | > def makedate(): |
|
7 | 6 | > return 0, 0 |
|
8 | 7 | > def getuser(): |
|
9 | 8 | > return 'bob' |
|
10 | 9 | > # mock the date and user apis so the output is always the same |
|
11 | 10 | > def uisetup(ui): |
|
12 | 11 | > util.makedate = makedate |
|
13 |
> |
|
|
12 | > util.getuser = getuser | |
|
14 | 13 | > EOF |
|
15 | 14 | $ cat >> $HGRCPATH <<EOF |
|
16 | 15 | > [extensions] |
|
17 | 16 | > blackbox= |
|
18 | 17 | > mock=`pwd`/mock.py |
|
19 | 18 | > mq= |
|
20 | 19 | > EOF |
|
21 | 20 | $ hg init blackboxtest |
|
22 | 21 | $ cd blackboxtest |
|
23 | 22 | |
|
24 | 23 | command, exit codes, and duration |
|
25 | 24 | |
|
26 | 25 | $ echo a > a |
|
27 | 26 | $ hg add a |
|
28 | 27 | $ hg blackbox |
|
29 | 28 | 1970/01/01 00:00:00 bob> add a |
|
30 | 29 | 1970/01/01 00:00:00 bob> add exited 0 after * seconds (glob) |
|
31 | 30 | |
|
32 | 31 | incoming change tracking |
|
33 | 32 | |
|
34 | 33 | create two heads to verify that we only see one change in the log later |
|
35 | 34 | $ hg commit -ma |
|
36 | 35 | $ hg up null |
|
37 | 36 | 0 files updated, 0 files merged, 1 files removed, 0 files unresolved |
|
38 | 37 | $ echo b > b |
|
39 | 38 | $ hg commit -Amb |
|
40 | 39 | adding b |
|
41 | 40 | created new head |
|
42 | 41 | |
|
43 | 42 | clone, commit, pull |
|
44 | 43 | $ hg clone . ../blackboxtest2 |
|
45 | 44 | updating to branch default |
|
46 | 45 | 1 files updated, 0 files merged, 0 files removed, 0 files unresolved |
|
47 | 46 | $ echo c > c |
|
48 | 47 | $ hg commit -Amc |
|
49 | 48 | adding c |
|
50 | 49 | $ cd ../blackboxtest2 |
|
51 | 50 | $ hg pull |
|
52 | 51 | pulling from $TESTTMP/blackboxtest (glob) |
|
53 | 52 | searching for changes |
|
54 | 53 | adding changesets |
|
55 | 54 | adding manifests |
|
56 | 55 | adding file changes |
|
57 | 56 | added 1 changesets with 1 changes to 1 files |
|
58 | 57 | (run 'hg update' to get a working copy) |
|
59 | 58 | $ hg blackbox -l 3 |
|
60 | 59 | 1970/01/01 00:00:00 bob> pull |
|
61 | 60 | 1970/01/01 00:00:00 bob> 1 incoming changes - new heads: d02f48003e62 |
|
62 | 61 | 1970/01/01 00:00:00 bob> pull exited None after * seconds (glob) |
|
63 | 62 | |
|
64 | 63 | we must not cause a failure if we cannot write to the log |
|
65 | 64 | |
|
66 | 65 | $ hg rollback |
|
67 | 66 | repository tip rolled back to revision 1 (undo pull) |
|
68 | 67 | $ chmod 000 .hg/blackbox.log |
|
69 | 68 | $ hg --debug incoming |
|
70 | 69 | warning: cannot write to blackbox.log: Permission denied |
|
71 | 70 | comparing with $TESTTMP/blackboxtest |
|
72 | 71 | query 1; heads |
|
73 | 72 | searching for changes |
|
74 | 73 | all local heads known remotely |
|
75 | 74 | changeset: 2:d02f48003e62c24e2659d97d30f2a83abe5d5d51 |
|
76 | 75 | tag: tip |
|
77 | 76 | phase: draft |
|
78 | 77 | parent: 1:6563da9dcf87b1949716e38ff3e3dfaa3198eb06 |
|
79 | 78 | parent: -1:0000000000000000000000000000000000000000 |
|
80 | 79 | manifest: 2:ab9d46b053ebf45b7996f2922b9893ff4b63d892 |
|
81 | 80 | user: test |
|
82 | 81 | date: Thu Jan 01 00:00:00 1970 +0000 |
|
83 | 82 | files+: c |
|
84 | 83 | extra: branch=default |
|
85 | 84 | description: |
|
86 | 85 | c |
|
87 | 86 | |
|
88 | 87 | |
|
89 | 88 | $ hg pull |
|
90 | 89 | pulling from $TESTTMP/blackboxtest |
|
91 | 90 | searching for changes |
|
92 | 91 | adding changesets |
|
93 | 92 | adding manifests |
|
94 | 93 | adding file changes |
|
95 | 94 | added 1 changesets with 1 changes to 1 files |
|
96 | 95 | (run 'hg update' to get a working copy) |
|
97 | 96 | |
|
98 | 97 | a failure reading from the log is fine |
|
99 | 98 | |
|
100 | 99 | $ hg blackbox -l 3 |
|
101 | 100 | abort: Permission denied: $TESTTMP/blackboxtest2/.hg/blackbox.log |
|
102 | 101 | [255] |
|
103 | 102 | |
|
104 | 103 | $ chmod 600 .hg/blackbox.log |
|
105 | 104 | |
|
106 | 105 | backup bundles get logged |
|
107 | 106 | |
|
108 | 107 | $ touch d |
|
109 | 108 | $ hg commit -Amd |
|
110 | 109 | adding d |
|
111 | 110 | created new head |
|
112 | 111 | $ hg strip tip |
|
113 | 112 | 0 files updated, 0 files merged, 1 files removed, 0 files unresolved |
|
114 | 113 | saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob) |
|
115 | 114 | $ hg blackbox -l 3 |
|
116 | 115 | 1970/01/01 00:00:00 bob> strip tip |
|
117 | 116 | 1970/01/01 00:00:00 bob> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob) |
|
118 | 117 | 1970/01/01 00:00:00 bob> strip exited 0 after * seconds (glob) |
|
119 | 118 | |
|
120 | 119 | extension and python hooks - use the eol extension for a pythonhook |
|
121 | 120 | |
|
122 | 121 | $ echo '[extensions]' >> .hg/hgrc |
|
123 | 122 | $ echo 'eol=' >> .hg/hgrc |
|
124 | 123 | $ echo '[hooks]' >> .hg/hgrc |
|
125 | 124 | $ echo 'update = echo hooked' >> .hg/hgrc |
|
126 | 125 | $ hg update |
|
127 | 126 | hooked |
|
128 | 127 | 1 files updated, 0 files merged, 0 files removed, 0 files unresolved |
|
129 | 128 | $ hg blackbox -l 4 |
|
130 | 129 | 1970/01/01 00:00:00 bob> update |
|
131 | 130 | 1970/01/01 00:00:00 bob> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob) |
|
132 | 131 | 1970/01/01 00:00:00 bob> exthook-update: echo hooked finished in * seconds (glob) |
|
133 | 132 | 1970/01/01 00:00:00 bob> update exited False after * seconds (glob) |
|
134 | 133 | |
|
135 | 134 | cleanup |
|
136 | 135 | $ cd .. |
General Comments 0
You need to be logged in to leave comments.
Login now