Show More
@@ -1,243 +1,242 b'' | |||||
1 | # blackbox.py - log repository events to a file for post-mortem debugging |
|
1 | # blackbox.py - log repository events to a file for post-mortem debugging | |
2 | # |
|
2 | # | |
3 | # Copyright 2010 Nicolas Dumazet |
|
3 | # Copyright 2010 Nicolas Dumazet | |
4 | # Copyright 2013 Facebook, Inc. |
|
4 | # Copyright 2013 Facebook, Inc. | |
5 | # |
|
5 | # | |
6 | # This software may be used and distributed according to the terms of the |
|
6 | # This software may be used and distributed according to the terms of the | |
7 | # GNU General Public License version 2 or any later version. |
|
7 | # GNU General Public License version 2 or any later version. | |
8 |
|
8 | |||
9 | """log repository events to a blackbox for debugging |
|
9 | """log repository events to a blackbox for debugging | |
10 |
|
10 | |||
11 | Logs event information to .hg/blackbox.log to help debug and diagnose problems. |
|
11 | Logs event information to .hg/blackbox.log to help debug and diagnose problems. | |
12 | The events that get logged can be configured via the blackbox.track config key. |
|
12 | The events that get logged can be configured via the blackbox.track config key. | |
13 |
|
13 | |||
14 | If you want to record whether the repository is dirty (a `+` sign, as you'd |
|
|||
15 | get when using :hg:`id`), you can set the blackbox.dirty config key. |
|
|||
16 |
|
||||
17 | Examples:: |
|
14 | Examples:: | |
18 |
|
15 | |||
19 | [blackbox] |
|
16 | [blackbox] | |
20 | track = * |
|
17 | track = * | |
|
18 | # dirty is *EXPENSIVE* (slow); | |||
|
19 | # each log entry indicates `+` if the repository is dirty, like :hg:`id`. | |||
21 | dirty = True |
|
20 | dirty = True | |
22 |
|
21 | |||
23 | [blackbox] |
|
22 | [blackbox] | |
24 | track = command, commandfinish, commandexception, exthook, pythonhook |
|
23 | track = command, commandfinish, commandexception, exthook, pythonhook | |
25 |
|
24 | |||
26 | [blackbox] |
|
25 | [blackbox] | |
27 | track = incoming |
|
26 | track = incoming | |
28 |
|
27 | |||
29 | [blackbox] |
|
28 | [blackbox] | |
30 | # limit the size of a log file |
|
29 | # limit the size of a log file | |
31 | maxsize = 1.5 MB |
|
30 | maxsize = 1.5 MB | |
32 | # rotate up to N log files when the current one gets too big |
|
31 | # rotate up to N log files when the current one gets too big | |
33 | maxfiles = 3 |
|
32 | maxfiles = 3 | |
34 |
|
33 | |||
35 | """ |
|
34 | """ | |
36 |
|
35 | |||
37 | from __future__ import absolute_import |
|
36 | from __future__ import absolute_import | |
38 |
|
37 | |||
39 | import errno |
|
38 | import errno | |
40 | import re |
|
39 | import re | |
41 |
|
40 | |||
42 | from mercurial.i18n import _ |
|
41 | from mercurial.i18n import _ | |
43 | from mercurial.node import hex |
|
42 | from mercurial.node import hex | |
44 |
|
43 | |||
45 | from mercurial import ( |
|
44 | from mercurial import ( | |
46 | cmdutil, |
|
45 | cmdutil, | |
47 | ui as uimod, |
|
46 | ui as uimod, | |
48 | util, |
|
47 | util, | |
49 | ) |
|
48 | ) | |
50 |
|
49 | |||
51 | cmdtable = {} |
|
50 | cmdtable = {} | |
52 | command = cmdutil.command(cmdtable) |
|
51 | command = cmdutil.command(cmdtable) | |
53 | # Note for extension authors: ONLY specify testedwith = 'internal' for |
|
52 | # Note for extension authors: ONLY specify testedwith = 'internal' for | |
54 | # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should |
|
53 | # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should | |
55 | # be specifying the version(s) of Mercurial they are tested with, or |
|
54 | # be specifying the version(s) of Mercurial they are tested with, or | |
56 | # leave the attribute unspecified. |
|
55 | # leave the attribute unspecified. | |
57 | testedwith = 'internal' |
|
56 | testedwith = 'internal' | |
58 | lastui = None |
|
57 | lastui = None | |
59 |
|
58 | |||
60 | filehandles = {} |
|
59 | filehandles = {} | |
61 |
|
60 | |||
62 | def _openlog(vfs): |
|
61 | def _openlog(vfs): | |
63 | path = vfs.join('blackbox.log') |
|
62 | path = vfs.join('blackbox.log') | |
64 | if path in filehandles: |
|
63 | if path in filehandles: | |
65 | return filehandles[path] |
|
64 | return filehandles[path] | |
66 | filehandles[path] = fp = vfs('blackbox.log', 'a') |
|
65 | filehandles[path] = fp = vfs('blackbox.log', 'a') | |
67 | return fp |
|
66 | return fp | |
68 |
|
67 | |||
69 | def _closelog(vfs): |
|
68 | def _closelog(vfs): | |
70 | path = vfs.join('blackbox.log') |
|
69 | path = vfs.join('blackbox.log') | |
71 | fp = filehandles[path] |
|
70 | fp = filehandles[path] | |
72 | del filehandles[path] |
|
71 | del filehandles[path] | |
73 | fp.close() |
|
72 | fp.close() | |
74 |
|
73 | |||
75 | def hexfn(node): |
|
74 | def hexfn(node): | |
76 | if node is None: |
|
75 | if node is None: | |
77 | return None |
|
76 | return None | |
78 | else: |
|
77 | else: | |
79 | return hex(node) |
|
78 | return hex(node) | |
80 |
|
79 | |||
81 | def wrapui(ui): |
|
80 | def wrapui(ui): | |
82 | class blackboxui(ui.__class__): |
|
81 | class blackboxui(ui.__class__): | |
83 | def __init__(self, src=None): |
|
82 | def __init__(self, src=None): | |
84 | super(blackboxui, self).__init__(src) |
|
83 | super(blackboxui, self).__init__(src) | |
85 | if src is None: |
|
84 | if src is None: | |
86 | self._partialinit() |
|
85 | self._partialinit() | |
87 | else: |
|
86 | else: | |
88 | self._bbfp = src._bbfp |
|
87 | self._bbfp = src._bbfp | |
89 | self._bbrepo = src._bbrepo |
|
88 | self._bbrepo = src._bbrepo | |
90 | self._bbvfs = src._bbvfs |
|
89 | self._bbvfs = src._bbvfs | |
91 |
|
90 | |||
92 | def _partialinit(self): |
|
91 | def _partialinit(self): | |
93 | if util.safehasattr(self, '_bbvfs'): |
|
92 | if util.safehasattr(self, '_bbvfs'): | |
94 | return |
|
93 | return | |
95 | self._bbfp = None |
|
94 | self._bbfp = None | |
96 | self._bbrepo = None |
|
95 | self._bbrepo = None | |
97 | self._bbvfs = None |
|
96 | self._bbvfs = None | |
98 |
|
97 | |||
99 | def copy(self): |
|
98 | def copy(self): | |
100 | self._partialinit() |
|
99 | self._partialinit() | |
101 | return self.__class__(self) |
|
100 | return self.__class__(self) | |
102 |
|
101 | |||
103 | @util.propertycache |
|
102 | @util.propertycache | |
104 | def track(self): |
|
103 | def track(self): | |
105 | return self.configlist('blackbox', 'track', ['*']) |
|
104 | return self.configlist('blackbox', 'track', ['*']) | |
106 |
|
105 | |||
107 | def _openlogfile(self): |
|
106 | def _openlogfile(self): | |
108 | def rotate(oldpath, newpath): |
|
107 | def rotate(oldpath, newpath): | |
109 | try: |
|
108 | try: | |
110 | self._bbvfs.unlink(newpath) |
|
109 | self._bbvfs.unlink(newpath) | |
111 | except OSError as err: |
|
110 | except OSError as err: | |
112 | if err.errno != errno.ENOENT: |
|
111 | if err.errno != errno.ENOENT: | |
113 | self.debug("warning: cannot remove '%s': %s\n" % |
|
112 | self.debug("warning: cannot remove '%s': %s\n" % | |
114 | (newpath, err.strerror)) |
|
113 | (newpath, err.strerror)) | |
115 | try: |
|
114 | try: | |
116 | if newpath: |
|
115 | if newpath: | |
117 | self._bbvfs.rename(oldpath, newpath) |
|
116 | self._bbvfs.rename(oldpath, newpath) | |
118 | except OSError as err: |
|
117 | except OSError as err: | |
119 | if err.errno != errno.ENOENT: |
|
118 | if err.errno != errno.ENOENT: | |
120 | self.debug("warning: cannot rename '%s' to '%s': %s\n" % |
|
119 | self.debug("warning: cannot rename '%s' to '%s': %s\n" % | |
121 | (newpath, oldpath, err.strerror)) |
|
120 | (newpath, oldpath, err.strerror)) | |
122 |
|
121 | |||
123 | fp = _openlog(self._bbvfs) |
|
122 | fp = _openlog(self._bbvfs) | |
124 | maxsize = self.configbytes('blackbox', 'maxsize', 1048576) |
|
123 | maxsize = self.configbytes('blackbox', 'maxsize', 1048576) | |
125 | if maxsize > 0: |
|
124 | if maxsize > 0: | |
126 | st = self._bbvfs.fstat(fp) |
|
125 | st = self._bbvfs.fstat(fp) | |
127 | if st.st_size >= maxsize: |
|
126 | if st.st_size >= maxsize: | |
128 | path = fp.name |
|
127 | path = fp.name | |
129 | _closelog(self._bbvfs) |
|
128 | _closelog(self._bbvfs) | |
130 | maxfiles = self.configint('blackbox', 'maxfiles', 7) |
|
129 | maxfiles = self.configint('blackbox', 'maxfiles', 7) | |
131 | for i in xrange(maxfiles - 1, 1, -1): |
|
130 | for i in xrange(maxfiles - 1, 1, -1): | |
132 | rotate(oldpath='%s.%d' % (path, i - 1), |
|
131 | rotate(oldpath='%s.%d' % (path, i - 1), | |
133 | newpath='%s.%d' % (path, i)) |
|
132 | newpath='%s.%d' % (path, i)) | |
134 | rotate(oldpath=path, |
|
133 | rotate(oldpath=path, | |
135 | newpath=maxfiles > 0 and path + '.1') |
|
134 | newpath=maxfiles > 0 and path + '.1') | |
136 | fp = _openlog(self._bbvfs) |
|
135 | fp = _openlog(self._bbvfs) | |
137 | return fp |
|
136 | return fp | |
138 |
|
137 | |||
139 | def _bbwrite(self, fmt, *args): |
|
138 | def _bbwrite(self, fmt, *args): | |
140 | self._bbfp.write(fmt % args) |
|
139 | self._bbfp.write(fmt % args) | |
141 | self._bbfp.flush() |
|
140 | self._bbfp.flush() | |
142 |
|
141 | |||
143 | def log(self, event, *msg, **opts): |
|
142 | def log(self, event, *msg, **opts): | |
144 | global lastui |
|
143 | global lastui | |
145 | super(blackboxui, self).log(event, *msg, **opts) |
|
144 | super(blackboxui, self).log(event, *msg, **opts) | |
146 | self._partialinit() |
|
145 | self._partialinit() | |
147 |
|
146 | |||
148 | if not '*' in self.track and not event in self.track: |
|
147 | if not '*' in self.track and not event in self.track: | |
149 | return |
|
148 | return | |
150 |
|
149 | |||
151 | if self._bbfp: |
|
150 | if self._bbfp: | |
152 | ui = self |
|
151 | ui = self | |
153 | elif self._bbvfs: |
|
152 | elif self._bbvfs: | |
154 | try: |
|
153 | try: | |
155 | self._bbfp = self._openlogfile() |
|
154 | self._bbfp = self._openlogfile() | |
156 | except (IOError, OSError) as err: |
|
155 | except (IOError, OSError) as err: | |
157 | self.debug('warning: cannot write to blackbox.log: %s\n' % |
|
156 | self.debug('warning: cannot write to blackbox.log: %s\n' % | |
158 | err.strerror) |
|
157 | err.strerror) | |
159 | del self._bbvfs |
|
158 | del self._bbvfs | |
160 | self._bbfp = None |
|
159 | self._bbfp = None | |
161 | ui = self |
|
160 | ui = self | |
162 | else: |
|
161 | else: | |
163 | # certain ui instances exist outside the context of |
|
162 | # certain ui instances exist outside the context of | |
164 | # a repo, so just default to the last blackbox that |
|
163 | # a repo, so just default to the last blackbox that | |
165 | # was seen. |
|
164 | # was seen. | |
166 | ui = lastui |
|
165 | ui = lastui | |
167 |
|
166 | |||
168 | if ui and ui._bbfp: |
|
167 | if ui and ui._bbfp: | |
169 | date = util.datestr(None, '%Y/%m/%d %H:%M:%S') |
|
168 | date = util.datestr(None, '%Y/%m/%d %H:%M:%S') | |
170 | user = util.getuser() |
|
169 | user = util.getuser() | |
171 | pid = str(util.getpid()) |
|
170 | pid = str(util.getpid()) | |
172 | formattedmsg = msg[0] % msg[1:] |
|
171 | formattedmsg = msg[0] % msg[1:] | |
173 | rev = '(unknown)' |
|
172 | rev = '(unknown)' | |
174 | changed = '' |
|
173 | changed = '' | |
175 | if ui._bbrepo: |
|
174 | if ui._bbrepo: | |
176 | ctx = ui._bbrepo[None] |
|
175 | ctx = ui._bbrepo[None] | |
177 | if ctx.rev() is not None: |
|
176 | if ctx.rev() is not None: | |
178 | rev = hexfn(ctx.node()) |
|
177 | rev = hexfn(ctx.node()) | |
179 | else: |
|
178 | else: | |
180 | parents = ctx.parents() |
|
179 | parents = ctx.parents() | |
181 | rev = ('+'.join([hexfn(p.node()) for p in parents])) |
|
180 | rev = ('+'.join([hexfn(p.node()) for p in parents])) | |
182 | if (ui.configbool('blackbox', 'dirty', False) and ( |
|
181 | if (ui.configbool('blackbox', 'dirty', False) and ( | |
183 | any(ui._bbrepo.status()) or |
|
182 | any(ui._bbrepo.status()) or | |
184 | any(ctx.sub(s).dirty() for s in ctx.substate) |
|
183 | any(ctx.sub(s).dirty() for s in ctx.substate) | |
185 | )): |
|
184 | )): | |
186 | changed = '+' |
|
185 | changed = '+' | |
187 | try: |
|
186 | try: | |
188 | ui._bbwrite('%s %s @%s%s (%s)> %s', |
|
187 | ui._bbwrite('%s %s @%s%s (%s)> %s', | |
189 | date, user, rev, changed, pid, formattedmsg) |
|
188 | date, user, rev, changed, pid, formattedmsg) | |
190 | except IOError as err: |
|
189 | except IOError as err: | |
191 | self.debug('warning: cannot write to blackbox.log: %s\n' % |
|
190 | self.debug('warning: cannot write to blackbox.log: %s\n' % | |
192 | err.strerror) |
|
191 | err.strerror) | |
193 | if not lastui or ui._bbrepo: |
|
192 | if not lastui or ui._bbrepo: | |
194 | lastui = ui |
|
193 | lastui = ui | |
195 |
|
194 | |||
196 | def setrepo(self, repo): |
|
195 | def setrepo(self, repo): | |
197 | self._bbfp = None |
|
196 | self._bbfp = None | |
198 | self._bbrepo = repo |
|
197 | self._bbrepo = repo | |
199 | self._bbvfs = repo.vfs |
|
198 | self._bbvfs = repo.vfs | |
200 |
|
199 | |||
201 | ui.__class__ = blackboxui |
|
200 | ui.__class__ = blackboxui | |
202 | uimod.ui = blackboxui |
|
201 | uimod.ui = blackboxui | |
203 |
|
202 | |||
204 | def uisetup(ui): |
|
203 | def uisetup(ui): | |
205 | wrapui(ui) |
|
204 | wrapui(ui) | |
206 |
|
205 | |||
207 | def reposetup(ui, repo): |
|
206 | def reposetup(ui, repo): | |
208 | # During 'hg pull' a httppeer repo is created to represent the remote repo. |
|
207 | # During 'hg pull' a httppeer repo is created to represent the remote repo. | |
209 | # It doesn't have a .hg directory to put a blackbox in, so we don't do |
|
208 | # It doesn't have a .hg directory to put a blackbox in, so we don't do | |
210 | # the blackbox setup for it. |
|
209 | # the blackbox setup for it. | |
211 | if not repo.local(): |
|
210 | if not repo.local(): | |
212 | return |
|
211 | return | |
213 |
|
212 | |||
214 | if util.safehasattr(ui, 'setrepo'): |
|
213 | if util.safehasattr(ui, 'setrepo'): | |
215 | ui.setrepo(repo) |
|
214 | ui.setrepo(repo) | |
216 |
|
215 | |||
217 | @command('^blackbox', |
|
216 | @command('^blackbox', | |
218 | [('l', 'limit', 10, _('the number of events to show')), |
|
217 | [('l', 'limit', 10, _('the number of events to show')), | |
219 | ], |
|
218 | ], | |
220 | _('hg blackbox [OPTION]...')) |
|
219 | _('hg blackbox [OPTION]...')) | |
221 | def blackbox(ui, repo, *revs, **opts): |
|
220 | def blackbox(ui, repo, *revs, **opts): | |
222 | '''view the recent repository events |
|
221 | '''view the recent repository events | |
223 | ''' |
|
222 | ''' | |
224 |
|
223 | |||
225 | if not repo.vfs.exists('blackbox.log'): |
|
224 | if not repo.vfs.exists('blackbox.log'): | |
226 | return |
|
225 | return | |
227 |
|
226 | |||
228 | limit = opts.get('limit') |
|
227 | limit = opts.get('limit') | |
229 | fp = repo.vfs('blackbox.log', 'r') |
|
228 | fp = repo.vfs('blackbox.log', 'r') | |
230 | lines = fp.read().split('\n') |
|
229 | lines = fp.read().split('\n') | |
231 |
|
230 | |||
232 | count = 0 |
|
231 | count = 0 | |
233 | output = [] |
|
232 | output = [] | |
234 | for line in reversed(lines): |
|
233 | for line in reversed(lines): | |
235 | if count >= limit: |
|
234 | if count >= limit: | |
236 | break |
|
235 | break | |
237 |
|
236 | |||
238 | # count the commands by matching lines like: 2013/01/23 19:13:36 root> |
|
237 | # count the commands by matching lines like: 2013/01/23 19:13:36 root> | |
239 | if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line): |
|
238 | if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line): | |
240 | count += 1 |
|
239 | count += 1 | |
241 | output.append(line) |
|
240 | output.append(line) | |
242 |
|
241 | |||
243 | ui.status('\n'.join(reversed(output))) |
|
242 | ui.status('\n'.join(reversed(output))) |
General Comments 0
You need to be logged in to leave comments.
Login now