119 reportfunc(err, "hgext3rd.%s" % name, name) |
119 reportfunc(err, "hgext3rd.%s" % name, name) |
120 mod = _importh(name) |
120 mod = _importh(name) |
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)): |
134 for x in xs: |
133 for x in xs: |
135 _rejectunicode(name, x) |
134 _rejectunicode(name, x) |
164 o = getattr(mod, t, None) |
163 o = getattr(mod, t, None) |
165 if o: |
164 if o: |
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: |
173 shortname = name |
172 shortname = name |
174 if shortname in _builtin: |
173 if shortname in _builtin: |
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 |
186 # Before we do anything with the extension, check against minimum stated |
185 # Before we do anything with the extension, check against minimum stated |
187 # compatibility. This gives extension authors a mechanism to have their |
186 # compatibility. This gives extension authors a mechanism to have their |
191 if minver and util.versiontuple(minver, 2) > util.versiontuple(n=2): |
190 if minver and util.versiontuple(minver, 2) > util.versiontuple(n=2): |
192 msg = _('(third party extension %s requires version %s or newer ' |
191 msg = _('(third party extension %s requires version %s or newer ' |
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): |
209 uisetup = getattr(_extensions[name], 'uisetup', None) |
209 uisetup = getattr(_extensions[name], 'uisetup', None) |
210 if uisetup: |
210 if uisetup: |
233 ui.warn(_("*** failed to set up extension %s: %s\n") % (name, msg)) |
233 ui.warn(_("*** failed to set up extension %s: %s\n") % (name, msg)) |
234 return False |
234 return False |
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: |
263 ui.warn(_("*** failed to import extension %s from %s: %s\n") |
260 ui.warn(_("*** failed to import extension %s from %s: %s\n") |
264 % (name, path, msg)) |
261 % (name, path, msg)) |
267 % (name, msg)) |
264 % (name, msg)) |
268 if isinstance(inst, error.Hint) and inst.hint: |
265 if isinstance(inst, error.Hint) and inst.hint: |
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 |
277 # - loadermod is the module where loader is placed |
274 # - loadermod is the module where loader is placed |
278 # - loadername is the name of the function, |
275 # - loadername is the name of the function, |
281 # This one is for the list of item that must be run before running any setup |
278 # This one is for the list of item that must be run before running any setup |
282 earlyextraloaders = [ |
279 earlyextraloaders = [ |
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. |
335 _aftercallbacks.clear() |
335 _aftercallbacks.clear() |
336 |
336 |
350 # - objname is the name of an object in extension module, |
350 # - objname is the name of an object in extension module, |
351 # from which extra information is loaded |
351 # from which extra information is loaded |
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'), |
359 ('filesetpredicate', fileset, 'loadpredicate'), |
359 ('filesetpredicate', fileset, 'loadpredicate'), |
360 ('internalmerge', filemerge, 'loadinternalmerge'), |
360 ('internalmerge', filemerge, 'loadinternalmerge'), |
363 ('templatefunc', templatefuncs, 'loadfunction'), |
363 ('templatefunc', templatefuncs, 'loadfunction'), |
364 ('templatekeyword', templatekw, 'loadkeyword'), |
364 ('templatekeyword', templatekw, 'loadkeyword'), |
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:]: |
379 module = _extensions[name] |
380 module = _extensions[name] |
380 if not module: |
381 if not module: |