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