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