##// END OF EJS Templates
extensions: use ui.log() interface to provide detailed loading information...
Yuya Nishihara -
r41032:6f2510b5 default
parent child Browse files
Show More
@@ -121,13 +121,12 b' def _importext(name, path=None, reportfu'
121 return mod
121 return mod
122
122
123 def _reportimporterror(ui, err, failed, next):
123 def _reportimporterror(ui, err, failed, next):
124 # note: this ui.debug happens before --debug is processed,
124 # note: this ui.log happens before --debug is processed,
125 # Use --config ui.debug=1 to see them.
125 # Use --config ui.debug=1 to see them.
126 if ui.configbool('devel', 'debug.extensions'):
126 ui.log(b'extension', b' - could not import %s (%s): trying %s\n',
127 ui.debug('debug.extensions: - could not import %s (%s): trying %s\n'
127 failed, stringutil.forcebytestr(err), next)
128 % (failed, stringutil.forcebytestr(err), next))
128 if ui.debugflag and ui.configbool('devel', 'debug.extensions'):
129 if ui.debugflag:
129 ui.traceback()
130 ui.traceback()
131
130
132 def _rejectunicode(name, xs):
131 def _rejectunicode(name, xs):
133 if isinstance(xs, (list, set, tuple)):
132 if isinstance(xs, (list, set, tuple)):
@@ -166,7 +165,7 b' def _validatetables(ui, mod):'
166 _rejectunicode(t, o._table)
165 _rejectunicode(t, o._table)
167 _validatecmdtable(ui, getattr(mod, 'cmdtable', {}))
166 _validatecmdtable(ui, getattr(mod, 'cmdtable', {}))
168
167
169 def load(ui, name, path, log=lambda *a: None, loadingtime=None):
168 def load(ui, name, path, loadingtime=None):
170 if name.startswith('hgext.') or name.startswith('hgext/'):
169 if name.startswith('hgext.') or name.startswith('hgext/'):
171 shortname = name[6:]
170 shortname = name[6:]
172 else:
171 else:
@@ -175,11 +174,11 b' def load(ui, name, path, log=lambda *a: '
175 return None
174 return None
176 if shortname in _extensions:
175 if shortname in _extensions:
177 return _extensions[shortname]
176 return _extensions[shortname]
178 log(' - loading extension: %s\n', shortname)
177 ui.log(b'extension', b' - loading extension: %s\n', shortname)
179 _extensions[shortname] = None
178 _extensions[shortname] = None
180 with util.timedcm('load extension %s', shortname) as stats:
179 with util.timedcm('load extension %s', shortname) as stats:
181 mod = _importext(name, path, bind(_reportimporterror, ui))
180 mod = _importext(name, path, bind(_reportimporterror, ui))
182 log(' > %s extension loaded in %s\n', shortname, stats)
181 ui.log(b'extension', b' > %s extension loaded in %s\n', shortname, stats)
183 if loadingtime is not None:
182 if loadingtime is not None:
184 loadingtime[shortname] += stats.elapsed
183 loadingtime[shortname] += stats.elapsed
185
184
@@ -193,16 +192,17 b' def load(ui, name, path, log=lambda *a: '
193 'of Mercurial (current: %s); disabling)\n')
192 'of Mercurial (current: %s); disabling)\n')
194 ui.warn(msg % (shortname, minver, util.version()))
193 ui.warn(msg % (shortname, minver, util.version()))
195 return
194 return
196 log(' - validating extension tables: %s\n', shortname)
195 ui.log(b'extension', b' - validating extension tables: %s\n', shortname)
197 _validatetables(ui, mod)
196 _validatetables(ui, mod)
198
197
199 _extensions[shortname] = mod
198 _extensions[shortname] = mod
200 _order.append(shortname)
199 _order.append(shortname)
201 log(' - invoking registered callbacks: %s\n', shortname)
200 ui.log(b'extension', b' - invoking registered callbacks: %s\n',
201 shortname)
202 with util.timedcm('callbacks extension %s', shortname) as stats:
202 with util.timedcm('callbacks extension %s', shortname) as stats:
203 for fn in _aftercallbacks.get(shortname, []):
203 for fn in _aftercallbacks.get(shortname, []):
204 fn(loaded=True)
204 fn(loaded=True)
205 log(' > callbacks completed in %s\n', stats)
205 ui.log(b'extension', b' > callbacks completed in %s\n', stats)
206 return mod
206 return mod
207
207
208 def _runuisetup(name, ui):
208 def _runuisetup(name, ui):
@@ -235,28 +235,25 b' def _runextsetup(name, ui):'
235 return True
235 return True
236
236
237 def loadall(ui, whitelist=None):
237 def loadall(ui, whitelist=None):
238 if ui.configbool('devel', 'debug.extensions'):
239 log = lambda msg, *values: ui.debug('debug.extensions: ',
240 msg % values, label='debug.extensions')
241 else:
242 log = lambda *a, **kw: None
243 loadingtime = collections.defaultdict(int)
238 loadingtime = collections.defaultdict(int)
244 result = ui.configitems("extensions")
239 result = ui.configitems("extensions")
245 if whitelist is not None:
240 if whitelist is not None:
246 result = [(k, v) for (k, v) in result if k in whitelist]
241 result = [(k, v) for (k, v) in result if k in whitelist]
247 newindex = len(_order)
242 newindex = len(_order)
248 log('loading %sextensions\n', 'additional ' if newindex else '')
243 ui.log(b'extension', b'loading %sextensions\n',
249 log('- processing %d entries\n', len(result))
244 'additional ' if newindex else '')
245 ui.log(b'extension', b'- processing %d entries\n', len(result))
250 with util.timedcm('load all extensions') as stats:
246 with util.timedcm('load all extensions') as stats:
251 for (name, path) in result:
247 for (name, path) in result:
252 if path:
248 if path:
253 if path[0:1] == '!':
249 if path[0:1] == '!':
254 if name not in _disabledextensions:
250 if name not in _disabledextensions:
255 log(' - skipping disabled extension: %s\n', name)
251 ui.log(b'extension',
252 b' - skipping disabled extension: %s\n', name)
256 _disabledextensions[name] = path[1:]
253 _disabledextensions[name] = path[1:]
257 continue
254 continue
258 try:
255 try:
259 load(ui, name, path, log, loadingtime)
256 load(ui, name, path, loadingtime)
260 except Exception as inst:
257 except Exception as inst:
261 msg = stringutil.forcebytestr(inst)
258 msg = stringutil.forcebytestr(inst)
262 if path:
259 if path:
@@ -269,8 +266,8 b' def loadall(ui, whitelist=None):'
269 ui.warn(_("*** (%s)\n") % inst.hint)
266 ui.warn(_("*** (%s)\n") % inst.hint)
270 ui.traceback()
267 ui.traceback()
271
268
272 log('> loaded %d extensions, total time %s\n',
269 ui.log(b'extension', b'> loaded %d extensions, total time %s\n',
273 len(_order) - newindex, stats)
270 len(_order) - newindex, stats)
274 # list of (objname, loadermod, loadername) tuple:
271 # list of (objname, loadermod, loadername) tuple:
275 # - objname is the name of an object in extension module,
272 # - objname is the name of an object in extension module,
276 # from which extra information is loaded
273 # from which extra information is loaded
@@ -283,52 +280,55 b' def loadall(ui, whitelist=None):'
283 ('configtable', configitems, 'loadconfigtable'),
280 ('configtable', configitems, 'loadconfigtable'),
284 ]
281 ]
285
282
286 log('- loading configtable attributes\n')
283 ui.log(b'extension', b'- loading configtable attributes\n')
287 _loadextra(ui, newindex, earlyextraloaders)
284 _loadextra(ui, newindex, earlyextraloaders)
288
285
289 broken = set()
286 broken = set()
290 log('- executing uisetup hooks\n')
287 ui.log(b'extension', b'- executing uisetup hooks\n')
291 with util.timedcm('all uisetup') as alluisetupstats:
288 with util.timedcm('all uisetup') as alluisetupstats:
292 for name in _order[newindex:]:
289 for name in _order[newindex:]:
293 log(' - running uisetup for %s\n', name)
290 ui.log(b'extension', b' - running uisetup for %s\n', name)
294 with util.timedcm('uisetup %s', name) as stats:
291 with util.timedcm('uisetup %s', name) as stats:
295 if not _runuisetup(name, ui):
292 if not _runuisetup(name, ui):
296 log(' - the %s extension uisetup failed\n', name)
293 ui.log(b'extension',
294 b' - the %s extension uisetup failed\n', name)
297 broken.add(name)
295 broken.add(name)
298 log(' > uisetup for %s took %s\n', name, stats)
296 ui.log(b'extension', b' > uisetup for %s took %s\n', name, stats)
299 loadingtime[name] += stats.elapsed
297 loadingtime[name] += stats.elapsed
300 log('> all uisetup took %s\n', alluisetupstats)
298 ui.log(b'extension', b'> all uisetup took %s\n', alluisetupstats)
301
299
302 log('- executing extsetup hooks\n')
300 ui.log(b'extension', b'- executing extsetup hooks\n')
303 with util.timedcm('all extsetup') as allextetupstats:
301 with util.timedcm('all extsetup') as allextetupstats:
304 for name in _order[newindex:]:
302 for name in _order[newindex:]:
305 if name in broken:
303 if name in broken:
306 continue
304 continue
307 log(' - running extsetup for %s\n', name)
305 ui.log(b'extension', b' - running extsetup for %s\n', name)
308 with util.timedcm('extsetup %s', name) as stats:
306 with util.timedcm('extsetup %s', name) as stats:
309 if not _runextsetup(name, ui):
307 if not _runextsetup(name, ui):
310 log(' - the %s extension extsetup failed\n', name)
308 ui.log(b'extension',
309 b' - the %s extension extsetup failed\n', name)
311 broken.add(name)
310 broken.add(name)
312 log(' > extsetup for %s took %s\n', name, stats)
311 ui.log(b'extension', b' > extsetup for %s took %s\n', name, stats)
313 loadingtime[name] += stats.elapsed
312 loadingtime[name] += stats.elapsed
314 log('> all extsetup took %s\n', allextetupstats)
313 ui.log(b'extension', b'> all extsetup took %s\n', allextetupstats)
315
314
316 for name in broken:
315 for name in broken:
317 log(' - disabling broken %s extension\n', name)
316 ui.log(b'extension', b' - disabling broken %s extension\n', name)
318 _extensions[name] = None
317 _extensions[name] = None
319
318
320 # Call aftercallbacks that were never met.
319 # Call aftercallbacks that were never met.
321 log('- executing remaining aftercallbacks\n')
320 ui.log(b'extension', b'- executing remaining aftercallbacks\n')
322 with util.timedcm('aftercallbacks') as stats:
321 with util.timedcm('aftercallbacks') as stats:
323 for shortname in _aftercallbacks:
322 for shortname in _aftercallbacks:
324 if shortname in _extensions:
323 if shortname in _extensions:
325 continue
324 continue
326
325
327 for fn in _aftercallbacks[shortname]:
326 for fn in _aftercallbacks[shortname]:
328 log(' - extension %s not loaded, notify callbacks\n',
327 ui.log(b'extension',
329 shortname)
328 b' - extension %s not loaded, notify callbacks\n',
329 shortname)
330 fn(loaded=False)
330 fn(loaded=False)
331 log('> remaining aftercallbacks completed in %s\n', stats)
331 ui.log(b'extension', b'> remaining aftercallbacks completed in %s\n', stats)
332
332
333 # loadall() is called multiple times and lingering _aftercallbacks
333 # loadall() is called multiple times and lingering _aftercallbacks
334 # entries could result in double execution. See issue4646.
334 # entries could result in double execution. See issue4646.
@@ -352,7 +352,7 b' def loadall(ui, whitelist=None):'
352 # - loadermod is the module where loader is placed
352 # - loadermod is the module where loader is placed
353 # - loadername is the name of the function,
353 # - loadername is the name of the function,
354 # which takes (ui, extensionname, extraobj) arguments
354 # which takes (ui, extensionname, extraobj) arguments
355 log('- loading extension registration objects\n')
355 ui.log(b'extension', b'- loading extension registration objects\n')
356 extraloaders = [
356 extraloaders = [
357 ('cmdtable', commands, 'loadcmdtable'),
357 ('cmdtable', commands, 'loadcmdtable'),
358 ('colortable', color, 'loadcolortable'),
358 ('colortable', color, 'loadcolortable'),
@@ -365,14 +365,15 b' def loadall(ui, whitelist=None):'
365 ]
365 ]
366 with util.timedcm('load registration objects') as stats:
366 with util.timedcm('load registration objects') as stats:
367 _loadextra(ui, newindex, extraloaders)
367 _loadextra(ui, newindex, extraloaders)
368 log('> extension registration object loading took %s\n', stats)
368 ui.log(b'extension', b'> extension registration object loading took %s\n',
369 stats)
369
370
370 # Report per extension loading time (except reposetup)
371 # Report per extension loading time (except reposetup)
371 for name in sorted(loadingtime):
372 for name in sorted(loadingtime):
372 extension_msg = '> extension %s take a total of %s to load\n'
373 ui.log(b'extension', b'> extension %s take a total of %s to load\n',
373 log(extension_msg, name, util.timecount(loadingtime[name]))
374 name, util.timecount(loadingtime[name]))
374
375
375 log('extension loading complete\n')
376 ui.log(b'extension', b'extension loading complete\n')
376
377
377 def _loadextra(ui, newindex, extraloaders):
378 def _loadextra(ui, newindex, extraloaders):
378 for name in _order[newindex:]:
379 for name in _order[newindex:]:
@@ -160,23 +160,19 b' def _peerorrepo(ui, path, create=False, '
160 obj = _peerlookup(path).instance(ui, path, create, intents=intents,
160 obj = _peerlookup(path).instance(ui, path, create, intents=intents,
161 createopts=createopts)
161 createopts=createopts)
162 ui = getattr(obj, "ui", ui)
162 ui = getattr(obj, "ui", ui)
163 if ui.configbool('devel', 'debug.extensions'):
164 log = lambda msg, *values: ui.debug('debug.extensions: ',
165 msg % values, label='debug.extensions')
166 else:
167 log = lambda *a, **kw: None
168 for f in presetupfuncs or []:
163 for f in presetupfuncs or []:
169 f(ui, obj)
164 f(ui, obj)
170 log('- executing reposetup hooks\n')
165 ui.log(b'extension', b'- executing reposetup hooks\n')
171 with util.timedcm('all reposetup') as allreposetupstats:
166 with util.timedcm('all reposetup') as allreposetupstats:
172 for name, module in extensions.extensions(ui):
167 for name, module in extensions.extensions(ui):
173 log(' - running reposetup for %s\n' % (name,))
168 ui.log(b'extension', b' - running reposetup for %s\n', name)
174 hook = getattr(module, 'reposetup', None)
169 hook = getattr(module, 'reposetup', None)
175 if hook:
170 if hook:
176 with util.timedcm('reposetup %r', name) as stats:
171 with util.timedcm('reposetup %r', name) as stats:
177 hook(ui, obj)
172 hook(ui, obj)
178 log(' > reposetup for %s took %s\n', name, stats)
173 ui.log(b'extension', b' > reposetup for %s took %s\n',
179 log('> all reposetup took %s\n', allreposetupstats)
174 name, stats)
175 ui.log(b'extension', b'> all reposetup took %s\n', allreposetupstats)
180 if not obj.local():
176 if not obj.local():
181 for f in wirepeersetupfuncs:
177 for f in wirepeersetupfuncs:
182 f(ui, obj)
178 f(ui, obj)
@@ -1,3 +1,7 b''
1 $ filterlog () {
2 > sed -e 's!^[0-9/]* [0-9:]* ([0-9]*)>!YYYY/MM/DD HH:MM:SS (PID)>!'
3 > }
4
1 ensure that failing ui.atexit handlers report sensibly
5 ensure that failing ui.atexit handlers report sensibly
2
6
3 $ cat > $TESTTMP/bailatexit.py <<EOF
7 $ cat > $TESTTMP/bailatexit.py <<EOF
@@ -82,29 +86,30 b' show traceback for ImportError of hgext.'
82
86
83 $ (hg help help --traceback --debug --config devel.debug.extensions=yes 2>&1) \
87 $ (hg help help --traceback --debug --config devel.debug.extensions=yes 2>&1) \
84 > | grep -v '^ ' \
88 > | grep -v '^ ' \
85 > | egrep 'extension..[^p]|^Exception|Traceback|ImportError|not import|ModuleNotFound'
89 > | filterlog \
86 debug.extensions: loading extensions
90 > | egrep 'extension..[^p]|^Exception|Traceback|ImportError|^YYYY|not import|ModuleNotFound'
87 debug.extensions: - processing 5 entries
91 YYYY/MM/DD HH:MM:SS (PID)> loading extensions
88 debug.extensions: - loading extension: gpg
92 YYYY/MM/DD HH:MM:SS (PID)> - processing 5 entries
89 debug.extensions: > gpg extension loaded in * (glob)
93 YYYY/MM/DD HH:MM:SS (PID)> - loading extension: gpg
90 debug.extensions: - validating extension tables: gpg
94 YYYY/MM/DD HH:MM:SS (PID)> > gpg extension loaded in * (glob)
91 debug.extensions: - invoking registered callbacks: gpg
95 YYYY/MM/DD HH:MM:SS (PID)> - validating extension tables: gpg
92 debug.extensions: > callbacks completed in * (glob)
96 YYYY/MM/DD HH:MM:SS (PID)> - invoking registered callbacks: gpg
93 debug.extensions: - loading extension: badext
97 YYYY/MM/DD HH:MM:SS (PID)> > callbacks completed in * (glob)
98 YYYY/MM/DD HH:MM:SS (PID)> - loading extension: badext
94 *** failed to import extension badext from $TESTTMP/badext.py: bit bucket overflow
99 *** failed to import extension badext from $TESTTMP/badext.py: bit bucket overflow
95 Traceback (most recent call last):
100 Traceback (most recent call last):
96 Exception: bit bucket overflow
101 Exception: bit bucket overflow
97 debug.extensions: - loading extension: baddocext
102 YYYY/MM/DD HH:MM:SS (PID)> - loading extension: baddocext
98 debug.extensions: > baddocext extension loaded in * (glob)
103 YYYY/MM/DD HH:MM:SS (PID)> > baddocext extension loaded in * (glob)
99 debug.extensions: - validating extension tables: baddocext
104 YYYY/MM/DD HH:MM:SS (PID)> - validating extension tables: baddocext
100 debug.extensions: - invoking registered callbacks: baddocext
105 YYYY/MM/DD HH:MM:SS (PID)> - invoking registered callbacks: baddocext
101 debug.extensions: > callbacks completed in * (glob)
106 YYYY/MM/DD HH:MM:SS (PID)> > callbacks completed in * (glob)
102 debug.extensions: - loading extension: badext2
107 YYYY/MM/DD HH:MM:SS (PID)> - loading extension: badext2
103 debug.extensions: - could not import hgext.badext2 (No module named *badext2*): trying hgext3rd.badext2 (glob)
108 YYYY/MM/DD HH:MM:SS (PID)> - could not import hgext.badext2 (No module named *badext2*): trying hgext3rd.badext2 (glob)
104 Traceback (most recent call last):
109 Traceback (most recent call last):
105 ImportError: No module named badext2 (no-py3 !)
110 ImportError: No module named badext2 (no-py3 !)
106 ModuleNotFoundError: No module named 'hgext.badext2' (py3 !)
111 ModuleNotFoundError: No module named 'hgext.badext2' (py3 !)
107 debug.extensions: - could not import hgext3rd.badext2 (No module named *badext2*): trying badext2 (glob)
112 YYYY/MM/DD HH:MM:SS (PID)> - could not import hgext3rd.badext2 (No module named *badext2*): trying badext2 (glob)
108 Traceback (most recent call last):
113 Traceback (most recent call last):
109 ImportError: No module named badext2 (no-py3 !)
114 ImportError: No module named badext2 (no-py3 !)
110 ModuleNotFoundError: No module named 'hgext.badext2' (py3 !)
115 ModuleNotFoundError: No module named 'hgext.badext2' (py3 !)
@@ -118,27 +123,27 b' show traceback for ImportError of hgext.'
118 Traceback (most recent call last): (py3 !)
123 Traceback (most recent call last): (py3 !)
119 ModuleNotFoundError: No module named 'badext2' (py3 !)
124 ModuleNotFoundError: No module named 'badext2' (py3 !)
120 ImportError: No module named badext2 (no-py3 !)
125 ImportError: No module named badext2 (no-py3 !)
121 debug.extensions: > loaded 2 extensions, total time * (glob)
126 YYYY/MM/DD HH:MM:SS (PID)> > loaded 2 extensions, total time * (glob)
122 debug.extensions: - loading configtable attributes
127 YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
123 debug.extensions: - executing uisetup hooks
128 YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
124 debug.extensions: - running uisetup for gpg
129 YYYY/MM/DD HH:MM:SS (PID)> - running uisetup for gpg
125 debug.extensions: > uisetup for gpg took * (glob)
130 YYYY/MM/DD HH:MM:SS (PID)> > uisetup for gpg took * (glob)
126 debug.extensions: - running uisetup for baddocext
131 YYYY/MM/DD HH:MM:SS (PID)> - running uisetup for baddocext
127 debug.extensions: > uisetup for baddocext took * (glob)
132 YYYY/MM/DD HH:MM:SS (PID)> > uisetup for baddocext took * (glob)
128 debug.extensions: > all uisetup took * (glob)
133 YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
129 debug.extensions: - executing extsetup hooks
134 YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
130 debug.extensions: - running extsetup for gpg
135 YYYY/MM/DD HH:MM:SS (PID)> - running extsetup for gpg
131 debug.extensions: > extsetup for gpg took * (glob)
136 YYYY/MM/DD HH:MM:SS (PID)> > extsetup for gpg took * (glob)
132 debug.extensions: - running extsetup for baddocext
137 YYYY/MM/DD HH:MM:SS (PID)> - running extsetup for baddocext
133 debug.extensions: > extsetup for baddocext took * (glob)
138 YYYY/MM/DD HH:MM:SS (PID)> > extsetup for baddocext took * (glob)
134 debug.extensions: > all extsetup took * (glob)
139 YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
135 debug.extensions: - executing remaining aftercallbacks
140 YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
136 debug.extensions: > remaining aftercallbacks completed in * (glob)
141 YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
137 debug.extensions: - loading extension registration objects
142 YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
138 debug.extensions: > extension registration object loading took * (glob)
143 YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
139 debug.extensions: > extension baddocext take a total of * to load (glob)
144 YYYY/MM/DD HH:MM:SS (PID)> > extension baddocext take a total of * to load (glob)
140 debug.extensions: > extension gpg take a total of * to load (glob)
145 YYYY/MM/DD HH:MM:SS (PID)> > extension gpg take a total of * to load (glob)
141 debug.extensions: extension loading complete
146 YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
142 #endif
147 #endif
143
148
144 confirm that there's no crash when an extension's documentation is bad
149 confirm that there's no crash when an extension's documentation is bad
@@ -41,54 +41,58 b' Test basic extension support'
41 $ echo '[extensions]' >> $HGRCPATH
41 $ echo '[extensions]' >> $HGRCPATH
42 $ echo "foobar = $abspath" >> $HGRCPATH
42 $ echo "foobar = $abspath" >> $HGRCPATH
43
43
44 $ filterlog () {
45 > sed -e 's!^[0-9/]* [0-9:]* ([0-9]*)>!YYYY/MM/DD HH:MM:SS (PID)>!'
46 > }
47
44 Test extension setup timings
48 Test extension setup timings
45
49
46 $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1
50 $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1 | filterlog
47 debug.extensions: loading extensions
51 YYYY/MM/DD HH:MM:SS (PID)> loading extensions
48 debug.extensions: - processing 1 entries
52 YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
49 debug.extensions: - loading extension: foobar
53 YYYY/MM/DD HH:MM:SS (PID)> - loading extension: foobar
50 debug.extensions: > foobar extension loaded in * (glob)
54 YYYY/MM/DD HH:MM:SS (PID)> > foobar extension loaded in * (glob)
51 debug.extensions: - validating extension tables: foobar
55 YYYY/MM/DD HH:MM:SS (PID)> - validating extension tables: foobar
52 debug.extensions: - invoking registered callbacks: foobar
56 YYYY/MM/DD HH:MM:SS (PID)> - invoking registered callbacks: foobar
53 debug.extensions: > callbacks completed in * (glob)
57 YYYY/MM/DD HH:MM:SS (PID)> > callbacks completed in * (glob)
54 debug.extensions: > loaded 1 extensions, total time * (glob)
58 YYYY/MM/DD HH:MM:SS (PID)> > loaded 1 extensions, total time * (glob)
55 debug.extensions: - loading configtable attributes
59 YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
56 debug.extensions: - executing uisetup hooks
60 YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
57 debug.extensions: - running uisetup for foobar
61 YYYY/MM/DD HH:MM:SS (PID)> - running uisetup for foobar
58 uisetup called [debug]
62 uisetup called [debug]
59 uisetup called
63 uisetup called
60 uisetup called [status]
64 uisetup called [status]
61 debug.extensions: > uisetup for foobar took * (glob)
65 YYYY/MM/DD HH:MM:SS (PID)> > uisetup for foobar took * (glob)
62 debug.extensions: > all uisetup took * (glob)
66 YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
63 debug.extensions: - executing extsetup hooks
67 YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
64 debug.extensions: - running extsetup for foobar
68 YYYY/MM/DD HH:MM:SS (PID)> - running extsetup for foobar
65 debug.extensions: > extsetup for foobar took * (glob)
69 YYYY/MM/DD HH:MM:SS (PID)> > extsetup for foobar took * (glob)
66 debug.extensions: > all extsetup took * (glob)
70 YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
67 debug.extensions: - executing remaining aftercallbacks
71 YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
68 debug.extensions: > remaining aftercallbacks completed in * (glob)
72 YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
69 debug.extensions: - loading extension registration objects
73 YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
70 debug.extensions: > extension registration object loading took * (glob)
74 YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
71 debug.extensions: > extension foobar take a total of * to load (glob)
75 YYYY/MM/DD HH:MM:SS (PID)> > extension foobar take a total of * to load (glob)
72 debug.extensions: extension loading complete
76 YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
73 debug.extensions: loading additional extensions
77 YYYY/MM/DD HH:MM:SS (PID)> loading additional extensions
74 debug.extensions: - processing 1 entries
78 YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
75 debug.extensions: > loaded 0 extensions, total time * (glob)
79 YYYY/MM/DD HH:MM:SS (PID)> > loaded 0 extensions, total time * (glob)
76 debug.extensions: - loading configtable attributes
80 YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
77 debug.extensions: - executing uisetup hooks
81 YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
78 debug.extensions: > all uisetup took * (glob)
82 YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
79 debug.extensions: - executing extsetup hooks
83 YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
80 debug.extensions: > all extsetup took * (glob)
84 YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
81 debug.extensions: - executing remaining aftercallbacks
85 YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
82 debug.extensions: > remaining aftercallbacks completed in * (glob)
86 YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
83 debug.extensions: - loading extension registration objects
87 YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
84 debug.extensions: > extension registration object loading took * (glob)
88 YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
85 debug.extensions: extension loading complete
89 YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
86 debug.extensions: - executing reposetup hooks
90 YYYY/MM/DD HH:MM:SS (PID)> - executing reposetup hooks
87 debug.extensions: - running reposetup for foobar
91 YYYY/MM/DD HH:MM:SS (PID)> - running reposetup for foobar
88 reposetup called for a
92 reposetup called for a
89 ui == repo.ui
93 ui == repo.ui
90 debug.extensions: > reposetup for foobar took * (glob)
94 YYYY/MM/DD HH:MM:SS (PID)> > reposetup for foobar took * (glob)
91 debug.extensions: > all reposetup took * (glob)
95 YYYY/MM/DD HH:MM:SS (PID)> > all reposetup took * (glob)
92 Foo
96 Foo
93
97
94 $ cd ..
98 $ cd ..
General Comments 0
You need to be logged in to leave comments. Login now