comparison tests/test-extension-timing.t @ 40996:6f2510b581a0

extensions: use ui.log() interface to provide detailed loading information The output format changes and the messages will be sent to stderr instead of stdout, but I don't think that matters.
author Yuya Nishihara <yuya@tcha.org>
date Sat, 15 Dec 2018 16:28:29 +0900
parents 09a37a5d8f5d
children 8cab8db59b6c
comparison
equal deleted inserted replaced
40995:19178aeb9b43 40996:6f2510b581a0
39 $ hg commit -m 'add file' 39 $ hg commit -m 'add file'
40 40
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 ..
95 99
96 $ echo 'foobar = !' >> $HGRCPATH 100 $ echo 'foobar = !' >> $HGRCPATH