##// END OF EJS Templates
blackbox: initialize repo attribute properly...
Yuya Nishihara -
r40682:179c02ba default
parent child Browse files
Show More
@@ -1,274 +1,274 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 _lastlogger = None
94 _lastlogger = 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 class blackboxlogger(object):
130 class blackboxlogger(object):
131 def __init__(self, ui):
131 def __init__(self, ui):
132 self._repo = None
132 self.track = ui.configlist('blackbox', 'track')
133 self.track = ui.configlist('blackbox', 'track')
133
134
134 @property
135 @property
135 def _bbvfs(self):
136 def _bbvfs(self):
136 vfs = None
137 vfs = None
137 repo = getattr(self, '_bbrepo', None)
138 if self._repo:
138 if repo:
139 vfs = self._repo.vfs
139 vfs = repo.vfs
140 if not vfs.isdir('.'):
140 if not vfs.isdir('.'):
141 vfs = None
141 vfs = None
142 return vfs
142 return vfs
143
143
144 def log(self, ui, event, msg, opts):
144 def log(self, ui, event, msg, opts):
145 global _lastlogger
145 global _lastlogger
146 if not '*' in self.track and not event in self.track:
146 if not '*' in self.track and not event in self.track:
147 return
147 return
148
148
149 if self._bbvfs:
149 if self._bbvfs:
150 _lastlogger = self
150 _lastlogger = self
151 elif _lastlogger and _lastlogger._bbvfs:
151 elif _lastlogger and _lastlogger._bbvfs:
152 # certain logger instances exist outside the context of
152 # certain logger instances exist outside the context of
153 # a repo, so just default to the last blackbox logger that
153 # a repo, so just default to the last blackbox logger that
154 # was seen.
154 # was seen.
155 pass
155 pass
156 else:
156 else:
157 return
157 return
158 _lastlogger._log(ui, event, msg, opts)
158 _lastlogger._log(ui, event, msg, opts)
159
159
160 def _log(self, ui, event, msg, opts):
160 def _log(self, ui, event, msg, opts):
161 if getattr(self, '_bbinlog', False):
161 if getattr(self, '_bbinlog', False):
162 # recursion and failure guard
162 # recursion and failure guard
163 return
163 return
164 self._bbinlog = True
164 self._bbinlog = True
165 default = ui.configdate('devel', 'default-date')
165 default = ui.configdate('devel', 'default-date')
166 date = dateutil.datestr(default, ui.config('blackbox', 'date-format'))
166 date = dateutil.datestr(default, ui.config('blackbox', 'date-format'))
167 user = procutil.getuser()
167 user = procutil.getuser()
168 pid = '%d' % procutil.getpid()
168 pid = '%d' % procutil.getpid()
169 formattedmsg = msg[0] % msg[1:]
169 formattedmsg = msg[0] % msg[1:]
170 rev = '(unknown)'
170 rev = '(unknown)'
171 changed = ''
171 changed = ''
172 ctx = self._bbrepo[None]
172 ctx = self._repo[None]
173 parents = ctx.parents()
173 parents = ctx.parents()
174 rev = ('+'.join([hex(p.node()) for p in parents]))
174 rev = ('+'.join([hex(p.node()) for p in parents]))
175 if (ui.configbool('blackbox', 'dirty') and
175 if (ui.configbool('blackbox', 'dirty') and
176 ctx.dirty(missing=True, merge=False, branch=False)):
176 ctx.dirty(missing=True, merge=False, branch=False)):
177 changed = '+'
177 changed = '+'
178 if ui.configbool('blackbox', 'logsource'):
178 if ui.configbool('blackbox', 'logsource'):
179 src = ' [%s]' % event
179 src = ' [%s]' % event
180 else:
180 else:
181 src = ''
181 src = ''
182 try:
182 try:
183 fmt = '%s %s @%s%s (%s)%s> %s'
183 fmt = '%s %s @%s%s (%s)%s> %s'
184 args = (date, user, rev, changed, pid, src, formattedmsg)
184 args = (date, user, rev, changed, pid, src, formattedmsg)
185 with _openlogfile(ui, self._bbvfs) as fp:
185 with _openlogfile(ui, self._bbvfs) as fp:
186 fp.write(fmt % args)
186 fp.write(fmt % args)
187 except (IOError, OSError) as err:
187 except (IOError, OSError) as err:
188 ui.debug('warning: cannot write to blackbox.log: %s\n' %
188 ui.debug('warning: cannot write to blackbox.log: %s\n' %
189 encoding.strtolocal(err.strerror))
189 encoding.strtolocal(err.strerror))
190 # do not restore _bbinlog intentionally to avoid failed
190 # do not restore _bbinlog intentionally to avoid failed
191 # logging again
191 # logging again
192 else:
192 else:
193 self._bbinlog = False
193 self._bbinlog = False
194
194
195 def setrepo(self, repo):
195 def setrepo(self, repo):
196 self._bbrepo = repo
196 self._repo = repo
197
197
198 def wrapui(ui):
198 def wrapui(ui):
199 class blackboxui(ui.__class__):
199 class blackboxui(ui.__class__):
200 def __init__(self, src=None):
200 def __init__(self, src=None):
201 super(blackboxui, self).__init__(src)
201 super(blackboxui, self).__init__(src)
202 if src and r'_bblogger' in src.__dict__:
202 if src and r'_bblogger' in src.__dict__:
203 self._bblogger = src._bblogger
203 self._bblogger = src._bblogger
204
204
205 # trick to initialize logger after configuration is loaded, which
205 # trick to initialize logger after configuration is loaded, which
206 # can be replaced later with blackboxlogger(ui) in uisetup(), where
206 # can be replaced later with blackboxlogger(ui) in uisetup(), where
207 # both user and repo configurations should be available.
207 # both user and repo configurations should be available.
208 @util.propertycache
208 @util.propertycache
209 def _bblogger(self):
209 def _bblogger(self):
210 return blackboxlogger(self)
210 return blackboxlogger(self)
211
211
212 def debug(self, *msg, **opts):
212 def debug(self, *msg, **opts):
213 super(blackboxui, self).debug(*msg, **opts)
213 super(blackboxui, self).debug(*msg, **opts)
214 if self.debugflag:
214 if self.debugflag:
215 self.log('debug', '%s', ''.join(msg))
215 self.log('debug', '%s', ''.join(msg))
216
216
217 def log(self, event, *msg, **opts):
217 def log(self, event, *msg, **opts):
218 super(blackboxui, self).log(event, *msg, **opts)
218 super(blackboxui, self).log(event, *msg, **opts)
219 self._bblogger.log(self, event, msg, opts)
219 self._bblogger.log(self, event, msg, opts)
220
220
221 ui.__class__ = blackboxui
221 ui.__class__ = blackboxui
222 uimod.ui = blackboxui
222 uimod.ui = blackboxui
223
223
224 def uisetup(ui):
224 def uisetup(ui):
225 wrapui(ui)
225 wrapui(ui)
226
226
227 def reposetup(ui, repo):
227 def reposetup(ui, repo):
228 # During 'hg pull' a httppeer repo is created to represent the remote repo.
228 # During 'hg pull' a httppeer repo is created to represent the remote repo.
229 # It doesn't have a .hg directory to put a blackbox in, so we don't do
229 # It doesn't have a .hg directory to put a blackbox in, so we don't do
230 # the blackbox setup for it.
230 # the blackbox setup for it.
231 if not repo.local():
231 if not repo.local():
232 return
232 return
233
233
234 logger = getattr(ui, '_bblogger', None)
234 logger = getattr(ui, '_bblogger', None)
235 if logger:
235 if logger:
236 logger.setrepo(repo)
236 logger.setrepo(repo)
237
237
238 # Set _lastlogger even if ui.log is not called. This gives blackbox a
238 # Set _lastlogger even if ui.log is not called. This gives blackbox a
239 # fallback place to log.
239 # fallback place to log.
240 global _lastlogger
240 global _lastlogger
241 if _lastlogger is None:
241 if _lastlogger is None:
242 _lastlogger = logger
242 _lastlogger = logger
243
243
244 repo._wlockfreeprefix.add('blackbox.log')
244 repo._wlockfreeprefix.add('blackbox.log')
245
245
246 @command('blackbox',
246 @command('blackbox',
247 [('l', 'limit', 10, _('the number of events to show')),
247 [('l', 'limit', 10, _('the number of events to show')),
248 ],
248 ],
249 _('hg blackbox [OPTION]...'),
249 _('hg blackbox [OPTION]...'),
250 helpcategory=command.CATEGORY_MAINTENANCE,
250 helpcategory=command.CATEGORY_MAINTENANCE,
251 helpbasic=True)
251 helpbasic=True)
252 def blackbox(ui, repo, *revs, **opts):
252 def blackbox(ui, repo, *revs, **opts):
253 '''view the recent repository events
253 '''view the recent repository events
254 '''
254 '''
255
255
256 if not repo.vfs.exists('blackbox.log'):
256 if not repo.vfs.exists('blackbox.log'):
257 return
257 return
258
258
259 limit = opts.get(r'limit')
259 limit = opts.get(r'limit')
260 fp = repo.vfs('blackbox.log', 'r')
260 fp = repo.vfs('blackbox.log', 'r')
261 lines = fp.read().split('\n')
261 lines = fp.read().split('\n')
262
262
263 count = 0
263 count = 0
264 output = []
264 output = []
265 for line in reversed(lines):
265 for line in reversed(lines):
266 if count >= limit:
266 if count >= limit:
267 break
267 break
268
268
269 # count the commands by matching lines like: 2013/01/23 19:13:36 root>
269 # count the commands by matching lines like: 2013/01/23 19:13:36 root>
270 if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line):
270 if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line):
271 count += 1
271 count += 1
272 output.append(line)
272 output.append(line)
273
273
274 ui.status('\n'.join(reversed(output)))
274 ui.status('\n'.join(reversed(output)))
General Comments 0
You need to be logged in to leave comments. Login now