##// END OF EJS Templates
blackbox: pass in options to _openlogfile() as arguments...
Yuya Nishihara -
r40829:644adf9c default
parent child Browse files
Show More
@@ -1,229 +1,230 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 )
55 )
56 from mercurial.utils import (
56 from mercurial.utils import (
57 dateutil,
57 dateutil,
58 procutil,
58 procutil,
59 )
59 )
60
60
61 # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for
61 # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for
62 # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should
62 # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should
63 # be specifying the version(s) of Mercurial they are tested with, or
63 # be specifying the version(s) of Mercurial they are tested with, or
64 # leave the attribute unspecified.
64 # leave the attribute unspecified.
65 testedwith = 'ships-with-hg-core'
65 testedwith = 'ships-with-hg-core'
66
66
67 cmdtable = {}
67 cmdtable = {}
68 command = registrar.command(cmdtable)
68 command = registrar.command(cmdtable)
69
69
70 configtable = {}
70 configtable = {}
71 configitem = registrar.configitem(configtable)
71 configitem = registrar.configitem(configtable)
72
72
73 configitem('blackbox', 'dirty',
73 configitem('blackbox', 'dirty',
74 default=False,
74 default=False,
75 )
75 )
76 configitem('blackbox', 'maxsize',
76 configitem('blackbox', 'maxsize',
77 default='1 MB',
77 default='1 MB',
78 )
78 )
79 configitem('blackbox', 'logsource',
79 configitem('blackbox', 'logsource',
80 default=False,
80 default=False,
81 )
81 )
82 configitem('blackbox', 'maxfiles',
82 configitem('blackbox', 'maxfiles',
83 default=7,
83 default=7,
84 )
84 )
85 configitem('blackbox', 'track',
85 configitem('blackbox', 'track',
86 default=lambda: ['*'],
86 default=lambda: ['*'],
87 )
87 )
88 configitem('blackbox', 'date-format',
88 configitem('blackbox', 'date-format',
89 default='%Y/%m/%d %H:%M:%S',
89 default='%Y/%m/%d %H:%M:%S',
90 )
90 )
91
91
92 def _openlogfile(ui, vfs):
92 def _openlogfile(ui, vfs, name, maxfiles=0, maxsize=0):
93 def rotate(oldpath, newpath):
93 def rotate(oldpath, newpath):
94 try:
94 try:
95 vfs.unlink(newpath)
95 vfs.unlink(newpath)
96 except OSError as err:
96 except OSError as err:
97 if err.errno != errno.ENOENT:
97 if err.errno != errno.ENOENT:
98 ui.debug("warning: cannot remove '%s': %s\n" %
98 ui.debug("warning: cannot remove '%s': %s\n" %
99 (newpath, err.strerror))
99 (newpath, err.strerror))
100 try:
100 try:
101 if newpath:
101 if newpath:
102 vfs.rename(oldpath, newpath)
102 vfs.rename(oldpath, newpath)
103 except OSError as err:
103 except OSError as err:
104 if err.errno != errno.ENOENT:
104 if err.errno != errno.ENOENT:
105 ui.debug("warning: cannot rename '%s' to '%s': %s\n" %
105 ui.debug("warning: cannot rename '%s' to '%s': %s\n" %
106 (newpath, oldpath, err.strerror))
106 (newpath, oldpath, err.strerror))
107
107
108 maxsize = ui.configbytes('blackbox', 'maxsize')
109 name = 'blackbox.log'
110 if maxsize > 0:
108 if maxsize > 0:
111 try:
109 try:
112 st = vfs.stat(name)
110 st = vfs.stat(name)
113 except OSError:
111 except OSError:
114 pass
112 pass
115 else:
113 else:
116 if st.st_size >= maxsize:
114 if st.st_size >= maxsize:
117 path = vfs.join(name)
115 path = vfs.join(name)
118 maxfiles = ui.configint('blackbox', 'maxfiles')
119 for i in pycompat.xrange(maxfiles - 1, 1, -1):
116 for i in pycompat.xrange(maxfiles - 1, 1, -1):
120 rotate(oldpath='%s.%d' % (path, i - 1),
117 rotate(oldpath='%s.%d' % (path, i - 1),
121 newpath='%s.%d' % (path, i))
118 newpath='%s.%d' % (path, i))
122 rotate(oldpath=path,
119 rotate(oldpath=path,
123 newpath=maxfiles > 0 and path + '.1')
120 newpath=maxfiles > 0 and path + '.1')
124 return vfs(name, 'a', makeparentdirs=False)
121 return vfs(name, 'a', makeparentdirs=False)
125
122
126 class proxylogger(object):
123 class proxylogger(object):
127 """Forward log events to another logger to be set later"""
124 """Forward log events to another logger to be set later"""
128
125
129 def __init__(self):
126 def __init__(self):
130 self.logger = None
127 self.logger = None
131
128
132 def tracked(self, event):
129 def tracked(self, event):
133 return self.logger is not None and self.logger.tracked(event)
130 return self.logger is not None and self.logger.tracked(event)
134
131
135 def log(self, ui, event, msg, opts):
132 def log(self, ui, event, msg, opts):
136 assert self.logger is not None
133 assert self.logger is not None
137 self.logger.log(ui, event, msg, opts)
134 self.logger.log(ui, event, msg, opts)
138
135
139 _lastlogger = proxylogger()
136 _lastlogger = proxylogger()
140
137
141 class blackboxlogger(object):
138 class blackboxlogger(object):
142 def __init__(self, ui, repo):
139 def __init__(self, ui, repo):
143 self._repo = repo
140 self._repo = repo
144 self._trackedevents = set(ui.configlist('blackbox', 'track'))
141 self._trackedevents = set(ui.configlist('blackbox', 'track'))
142 self._maxfiles = ui.configint('blackbox', 'maxfiles')
143 self._maxsize = ui.configbytes('blackbox', 'maxsize')
145
144
146 def tracked(self, event):
145 def tracked(self, event):
147 return b'*' in self._trackedevents or event in self._trackedevents
146 return b'*' in self._trackedevents or event in self._trackedevents
148
147
149 def log(self, ui, event, msg, opts):
148 def log(self, ui, event, msg, opts):
150 default = ui.configdate('devel', 'default-date')
149 default = ui.configdate('devel', 'default-date')
151 date = dateutil.datestr(default, ui.config('blackbox', 'date-format'))
150 date = dateutil.datestr(default, ui.config('blackbox', 'date-format'))
152 user = procutil.getuser()
151 user = procutil.getuser()
153 pid = '%d' % procutil.getpid()
152 pid = '%d' % procutil.getpid()
154 rev = '(unknown)'
153 rev = '(unknown)'
155 changed = ''
154 changed = ''
156 ctx = self._repo[None]
155 ctx = self._repo[None]
157 parents = ctx.parents()
156 parents = ctx.parents()
158 rev = ('+'.join([hex(p.node()) for p in parents]))
157 rev = ('+'.join([hex(p.node()) for p in parents]))
159 if (ui.configbool('blackbox', 'dirty') and
158 if (ui.configbool('blackbox', 'dirty') and
160 ctx.dirty(missing=True, merge=False, branch=False)):
159 ctx.dirty(missing=True, merge=False, branch=False)):
161 changed = '+'
160 changed = '+'
162 if ui.configbool('blackbox', 'logsource'):
161 if ui.configbool('blackbox', 'logsource'):
163 src = ' [%s]' % event
162 src = ' [%s]' % event
164 else:
163 else:
165 src = ''
164 src = ''
166 try:
165 try:
167 fmt = '%s %s @%s%s (%s)%s> %s'
166 fmt = '%s %s @%s%s (%s)%s> %s'
168 args = (date, user, rev, changed, pid, src, msg)
167 args = (date, user, rev, changed, pid, src, msg)
169 with _openlogfile(ui, self._repo.vfs) as fp:
168 with _openlogfile(ui, self._repo.vfs, name='blackbox.log',
169 maxfiles=self._maxfiles,
170 maxsize=self._maxsize) as fp:
170 fp.write(fmt % args)
171 fp.write(fmt % args)
171 except (IOError, OSError) as err:
172 except (IOError, OSError) as err:
172 # deactivate this to avoid failed logging again
173 # deactivate this to avoid failed logging again
173 self._trackedevents.clear()
174 self._trackedevents.clear()
174 ui.debug('warning: cannot write to blackbox.log: %s\n' %
175 ui.debug('warning: cannot write to blackbox.log: %s\n' %
175 encoding.strtolocal(err.strerror))
176 encoding.strtolocal(err.strerror))
176 return
177 return
177 _lastlogger.logger = self
178 _lastlogger.logger = self
178
179
179 def uipopulate(ui):
180 def uipopulate(ui):
180 ui.setlogger(b'blackbox', _lastlogger)
181 ui.setlogger(b'blackbox', _lastlogger)
181
182
182 def reposetup(ui, repo):
183 def reposetup(ui, repo):
183 # During 'hg pull' a httppeer repo is created to represent the remote repo.
184 # During 'hg pull' a httppeer repo is created to represent the remote repo.
184 # It doesn't have a .hg directory to put a blackbox in, so we don't do
185 # It doesn't have a .hg directory to put a blackbox in, so we don't do
185 # the blackbox setup for it.
186 # the blackbox setup for it.
186 if not repo.local():
187 if not repo.local():
187 return
188 return
188
189
189 # Since blackbox.log is stored in the repo directory, the logger should be
190 # Since blackbox.log is stored in the repo directory, the logger should be
190 # instantiated per repository.
191 # instantiated per repository.
191 logger = blackboxlogger(ui, repo)
192 logger = blackboxlogger(ui, repo)
192 ui.setlogger(b'blackbox', logger)
193 ui.setlogger(b'blackbox', logger)
193
194
194 # Set _lastlogger even if ui.log is not called. This gives blackbox a
195 # Set _lastlogger even if ui.log is not called. This gives blackbox a
195 # fallback place to log
196 # fallback place to log
196 if _lastlogger.logger is None:
197 if _lastlogger.logger is None:
197 _lastlogger.logger = logger
198 _lastlogger.logger = logger
198
199
199 repo._wlockfreeprefix.add('blackbox.log')
200 repo._wlockfreeprefix.add('blackbox.log')
200
201
201 @command('blackbox',
202 @command('blackbox',
202 [('l', 'limit', 10, _('the number of events to show')),
203 [('l', 'limit', 10, _('the number of events to show')),
203 ],
204 ],
204 _('hg blackbox [OPTION]...'),
205 _('hg blackbox [OPTION]...'),
205 helpcategory=command.CATEGORY_MAINTENANCE,
206 helpcategory=command.CATEGORY_MAINTENANCE,
206 helpbasic=True)
207 helpbasic=True)
207 def blackbox(ui, repo, *revs, **opts):
208 def blackbox(ui, repo, *revs, **opts):
208 '''view the recent repository events
209 '''view the recent repository events
209 '''
210 '''
210
211
211 if not repo.vfs.exists('blackbox.log'):
212 if not repo.vfs.exists('blackbox.log'):
212 return
213 return
213
214
214 limit = opts.get(r'limit')
215 limit = opts.get(r'limit')
215 fp = repo.vfs('blackbox.log', 'r')
216 fp = repo.vfs('blackbox.log', 'r')
216 lines = fp.read().split('\n')
217 lines = fp.read().split('\n')
217
218
218 count = 0
219 count = 0
219 output = []
220 output = []
220 for line in reversed(lines):
221 for line in reversed(lines):
221 if count >= limit:
222 if count >= limit:
222 break
223 break
223
224
224 # count the commands by matching lines like: 2013/01/23 19:13:36 root>
225 # count the commands by matching lines like: 2013/01/23 19:13:36 root>
225 if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line):
226 if re.match('^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2} .*> .*', line):
226 count += 1
227 count += 1
227 output.append(line)
228 output.append(line)
228
229
229 ui.status('\n'.join(reversed(output)))
230 ui.status('\n'.join(reversed(output)))
General Comments 0
You need to be logged in to leave comments. Login now