Show More
@@ -1,261 +1,258 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 | |
|
14 | 14 | Examples:: |
|
15 | 15 | |
|
16 | 16 | [blackbox] |
|
17 | 17 | track = * |
|
18 | 18 | # dirty is *EXPENSIVE* (slow); |
|
19 | 19 | # each log entry indicates `+` if the repository is dirty, like :hg:`id`. |
|
20 | 20 | dirty = True |
|
21 | 21 | # record the source of log messages |
|
22 | 22 | logsource = True |
|
23 | 23 | |
|
24 | 24 | [blackbox] |
|
25 | 25 | track = command, commandfinish, commandexception, exthook, pythonhook |
|
26 | 26 | |
|
27 | 27 | [blackbox] |
|
28 | 28 | track = incoming |
|
29 | 29 | |
|
30 | 30 | [blackbox] |
|
31 | 31 | # limit the size of a log file |
|
32 | 32 | maxsize = 1.5 MB |
|
33 | 33 | # rotate up to N log files when the current one gets too big |
|
34 | 34 | maxfiles = 3 |
|
35 | 35 | |
|
36 | 36 | [blackbox] |
|
37 | 37 | # Include nanoseconds in log entries with %f (see Python function |
|
38 | 38 | # datetime.datetime.strftime) |
|
39 | 39 | date-format = '%Y-%m-%d @ %H:%M:%S.%f' |
|
40 | 40 | |
|
41 | 41 | """ |
|
42 | 42 | |
|
43 | 43 | from __future__ import absolute_import |
|
44 | 44 | |
|
45 | 45 | import errno |
|
46 | 46 | import re |
|
47 | 47 | |
|
48 | 48 | from mercurial.i18n import _ |
|
49 | 49 | from mercurial.node import hex |
|
50 | 50 | |
|
51 | 51 | from mercurial import ( |
|
52 | 52 | encoding, |
|
53 | 53 | pycompat, |
|
54 | 54 | registrar, |
|
55 | 55 | ui as uimod, |
|
56 | 56 | util, |
|
57 | 57 | ) |
|
58 | 58 | from mercurial.utils import ( |
|
59 | 59 | dateutil, |
|
60 | 60 | procutil, |
|
61 | 61 | ) |
|
62 | 62 | |
|
63 | 63 | # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for |
|
64 | 64 | # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should |
|
65 | 65 | # be specifying the version(s) of Mercurial they are tested with, or |
|
66 | 66 | # leave the attribute unspecified. |
|
67 | 67 | testedwith = 'ships-with-hg-core' |
|
68 | 68 | |
|
69 | 69 | cmdtable = {} |
|
70 | 70 | command = registrar.command(cmdtable) |
|
71 | 71 | |
|
72 | 72 | configtable = {} |
|
73 | 73 | configitem = registrar.configitem(configtable) |
|
74 | 74 | |
|
75 | 75 | configitem('blackbox', 'dirty', |
|
76 | 76 | default=False, |
|
77 | 77 | ) |
|
78 | 78 | configitem('blackbox', 'maxsize', |
|
79 | 79 | default='1 MB', |
|
80 | 80 | ) |
|
81 | 81 | configitem('blackbox', 'logsource', |
|
82 | 82 | default=False, |
|
83 | 83 | ) |
|
84 | 84 | configitem('blackbox', 'maxfiles', |
|
85 | 85 | default=7, |
|
86 | 86 | ) |
|
87 | 87 | configitem('blackbox', 'track', |
|
88 | 88 | default=lambda: ['*'], |
|
89 | 89 | ) |
|
90 | 90 | configitem('blackbox', 'date-format', |
|
91 | 91 | default='%Y/%m/%d %H:%M:%S', |
|
92 | 92 | ) |
|
93 | 93 | |
|
94 | 94 | lastui = None |
|
95 | 95 | |
|
96 | 96 | def _openlogfile(ui, vfs): |
|
97 | 97 | def rotate(oldpath, newpath): |
|
98 | 98 | try: |
|
99 | 99 | vfs.unlink(newpath) |
|
100 | 100 | except OSError as err: |
|
101 | 101 | if err.errno != errno.ENOENT: |
|
102 | 102 | ui.debug("warning: cannot remove '%s': %s\n" % |
|
103 | 103 | (newpath, err.strerror)) |
|
104 | 104 | try: |
|
105 | 105 | if newpath: |
|
106 | 106 | vfs.rename(oldpath, newpath) |
|
107 | 107 | except OSError as err: |
|
108 | 108 | if err.errno != errno.ENOENT: |
|
109 | 109 | ui.debug("warning: cannot rename '%s' to '%s': %s\n" % |
|
110 | 110 | (newpath, oldpath, err.strerror)) |
|
111 | 111 | |
|
112 | 112 | maxsize = ui.configbytes('blackbox', 'maxsize') |
|
113 | 113 | name = 'blackbox.log' |
|
114 | 114 | if maxsize > 0: |
|
115 | 115 | try: |
|
116 | 116 | st = vfs.stat(name) |
|
117 | 117 | except OSError: |
|
118 | 118 | pass |
|
119 | 119 | else: |
|
120 | 120 | if st.st_size >= maxsize: |
|
121 | 121 | path = vfs.join(name) |
|
122 | 122 | maxfiles = ui.configint('blackbox', 'maxfiles') |
|
123 | 123 | for i in pycompat.xrange(maxfiles - 1, 1, -1): |
|
124 | 124 | rotate(oldpath='%s.%d' % (path, i - 1), |
|
125 | 125 | newpath='%s.%d' % (path, i)) |
|
126 | 126 | rotate(oldpath=path, |
|
127 | 127 | newpath=maxfiles > 0 and path + '.1') |
|
128 | 128 | return vfs(name, 'a') |
|
129 | 129 | |
|
130 | 130 | def wrapui(ui): |
|
131 | 131 | class blackboxui(ui.__class__): |
|
132 | 132 | @property |
|
133 | 133 | def _bbvfs(self): |
|
134 | 134 | vfs = None |
|
135 | 135 | repo = getattr(self, '_bbrepo', None) |
|
136 | 136 | if repo: |
|
137 | 137 | vfs = repo.vfs |
|
138 | 138 | if not vfs.isdir('.'): |
|
139 | 139 | vfs = None |
|
140 | 140 | return vfs |
|
141 | 141 | |
|
142 | 142 | @util.propertycache |
|
143 | 143 | def track(self): |
|
144 | 144 | return self.configlist('blackbox', 'track') |
|
145 | 145 | |
|
146 | 146 | def debug(self, *msg, **opts): |
|
147 | 147 | super(blackboxui, self).debug(*msg, **opts) |
|
148 | 148 | if self.debugflag: |
|
149 | 149 | self.log('debug', '%s', ''.join(msg)) |
|
150 | 150 | |
|
151 | 151 | def log(self, event, *msg, **opts): |
|
152 | 152 | global lastui |
|
153 | 153 | super(blackboxui, self).log(event, *msg, **opts) |
|
154 | 154 | |
|
155 | 155 | if not '*' in self.track and not event in self.track: |
|
156 | 156 | return |
|
157 | 157 | |
|
158 | 158 | if self._bbvfs: |
|
159 | 159 | ui = lastui = self |
|
160 | 160 | elif lastui and lastui._bbvfs: |
|
161 | 161 | # certain ui instances exist outside the context of |
|
162 | 162 | # a repo, so just default to the last blackbox that |
|
163 | 163 | # was seen. |
|
164 | 164 | ui = lastui |
|
165 | 165 | else: |
|
166 | 166 | return |
|
167 | 167 | |
|
168 | vfs = ui._bbvfs | |
|
169 | repo = ui._bbrepo | |
|
170 | ||
|
171 | 168 | if getattr(ui, '_bbinlog', False): |
|
172 | 169 | # recursion and failure guard |
|
173 | 170 | return |
|
174 | 171 | ui._bbinlog = True |
|
175 | 172 | default = self.configdate('devel', 'default-date') |
|
176 | 173 | date = dateutil.datestr(default, |
|
177 | 174 | ui.config('blackbox', 'date-format')) |
|
178 | 175 | user = procutil.getuser() |
|
179 | 176 | pid = '%d' % procutil.getpid() |
|
180 | 177 | formattedmsg = msg[0] % msg[1:] |
|
181 | 178 | rev = '(unknown)' |
|
182 | 179 | changed = '' |
|
183 | ctx = repo[None] | |
|
180 | ctx = ui._bbrepo[None] | |
|
184 | 181 | parents = ctx.parents() |
|
185 | 182 | rev = ('+'.join([hex(p.node()) for p in parents])) |
|
186 | 183 | if (ui.configbool('blackbox', 'dirty') and |
|
187 | 184 | ctx.dirty(missing=True, merge=False, branch=False)): |
|
188 | 185 | changed = '+' |
|
189 | 186 | if ui.configbool('blackbox', 'logsource'): |
|
190 | 187 | src = ' [%s]' % event |
|
191 | 188 | else: |
|
192 | 189 | src = '' |
|
193 | 190 | try: |
|
194 | 191 | fmt = '%s %s @%s%s (%s)%s> %s' |
|
195 | 192 | args = (date, user, rev, changed, pid, src, formattedmsg) |
|
196 | with _openlogfile(ui, vfs) as fp: | |
|
193 | with _openlogfile(ui, ui._bbvfs) as fp: | |
|
197 | 194 | fp.write(fmt % args) |
|
198 | 195 | except (IOError, OSError) as err: |
|
199 | 196 | self.debug('warning: cannot write to blackbox.log: %s\n' % |
|
200 | 197 | encoding.strtolocal(err.strerror)) |
|
201 | 198 | # do not restore _bbinlog intentionally to avoid failed |
|
202 | 199 | # logging again |
|
203 | 200 | else: |
|
204 | 201 | ui._bbinlog = False |
|
205 | 202 | |
|
206 | 203 | def setrepo(self, repo): |
|
207 | 204 | self._bbrepo = repo |
|
208 | 205 | |
|
209 | 206 | ui.__class__ = blackboxui |
|
210 | 207 | uimod.ui = blackboxui |
|
211 | 208 | |
|
212 | 209 | def uisetup(ui): |
|
213 | 210 | wrapui(ui) |
|
214 | 211 | |
|
215 | 212 | def reposetup(ui, repo): |
|
216 | 213 | # During 'hg pull' a httppeer repo is created to represent the remote repo. |
|
217 | 214 | # It doesn't have a .hg directory to put a blackbox in, so we don't do |
|
218 | 215 | # the blackbox setup for it. |
|
219 | 216 | if not repo.local(): |
|
220 | 217 | return |
|
221 | 218 | |
|
222 | 219 | if util.safehasattr(ui, 'setrepo'): |
|
223 | 220 | ui.setrepo(repo) |
|
224 | 221 | |
|
225 | 222 | # Set lastui even if ui.log is not called. This gives blackbox a |
|
226 | 223 | # fallback place to log. |
|
227 | 224 | global lastui |
|
228 | 225 | if lastui is None: |
|
229 | 226 | lastui = ui |
|
230 | 227 | |
|
231 | 228 | repo._wlockfreeprefix.add('blackbox.log') |
|
232 | 229 | |
|
233 | 230 | @command('blackbox', |
|
234 | 231 | [('l', 'limit', 10, _('the number of events to show')), |
|
235 | 232 | ], |
|
236 | 233 | _('hg blackbox [OPTION]...'), |
|
237 | 234 | helpcategory=command.CATEGORY_MAINTENANCE, |
|
238 | 235 | helpbasic=True) |
|
239 | 236 | def blackbox(ui, repo, *revs, **opts): |
|
240 | 237 | '''view the recent repository events |
|
241 | 238 | ''' |
|
242 | 239 | |
|
243 | 240 | if not repo.vfs.exists('blackbox.log'): |
|
244 | 241 | return |
|
245 | 242 | |
|
246 | 243 | limit = opts.get(r'limit') |
|
247 | 244 | fp = repo.vfs('blackbox.log', 'r') |
|
248 | 245 | lines = fp.read().split('\n') |
|
249 | 246 | |
|
250 | 247 | count = 0 |
|
251 | 248 | output = [] |
|
252 | 249 | for line in reversed(lines): |
|
253 | 250 | if count >= limit: |
|
254 | 251 | break |
|
255 | 252 | |
|
256 | 253 | # count the commands by matching lines like: 2013/01/23 19:13:36 root> |
|
257 | 254 | if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line): |
|
258 | 255 | count += 1 |
|
259 | 256 | output.append(line) |
|
260 | 257 | |
|
261 | 258 | ui.status('\n'.join(reversed(output))) |
General Comments 0
You need to be logged in to leave comments.
Login now