tests/test-extension-timing.t
changeset 40996 6f2510b581a0
parent 40440 09a37a5d8f5d
child 44619 8cab8db59b6c
--- a/tests/test-extension-timing.t	Sat Dec 15 16:52:04 2018 +0900
+++ b/tests/test-extension-timing.t	Sat Dec 15 16:28:29 2018 +0900
@@ -41,54 +41,58 @@
   $ echo '[extensions]' >> $HGRCPATH
   $ echo "foobar = $abspath" >> $HGRCPATH
 
+  $ filterlog () {
+  >   sed -e 's!^[0-9/]* [0-9:]* ([0-9]*)>!YYYY/MM/DD HH:MM:SS (PID)>!'
+  > }
+
 Test extension setup timings
 
-  $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1
-  debug.extensions: loading extensions
-  debug.extensions: - processing 1 entries
-  debug.extensions:   - loading extension: foobar
-  debug.extensions:   > foobar extension loaded in * (glob)
-  debug.extensions:     - validating extension tables: foobar
-  debug.extensions:     - invoking registered callbacks: foobar
-  debug.extensions:     > callbacks completed in * (glob)
-  debug.extensions: > loaded 1 extensions, total time * (glob)
-  debug.extensions: - loading configtable attributes
-  debug.extensions: - executing uisetup hooks
-  debug.extensions:   - running uisetup for foobar
+  $ hg foo --traceback --config devel.debug.extensions=yes --debug 2>&1 | filterlog
+  YYYY/MM/DD HH:MM:SS (PID)> loading extensions
+  YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
+  YYYY/MM/DD HH:MM:SS (PID)>   - loading extension: foobar
+  YYYY/MM/DD HH:MM:SS (PID)>   > foobar extension loaded in * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)>     - validating extension tables: foobar
+  YYYY/MM/DD HH:MM:SS (PID)>     - invoking registered callbacks: foobar
+  YYYY/MM/DD HH:MM:SS (PID)>     > callbacks completed in * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> > loaded 1 extensions, total time * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
+  YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
+  YYYY/MM/DD HH:MM:SS (PID)>   - running uisetup for foobar
   uisetup called [debug]
   uisetup called
   uisetup called [status]
-  debug.extensions:   > uisetup for foobar took * (glob)
-  debug.extensions: > all uisetup took * (glob)
-  debug.extensions: - executing extsetup hooks
-  debug.extensions:   - running extsetup for foobar
-  debug.extensions:   > extsetup for foobar took * (glob)
-  debug.extensions: > all extsetup took * (glob)
-  debug.extensions: - executing remaining aftercallbacks
-  debug.extensions: > remaining aftercallbacks completed in * (glob)
-  debug.extensions: - loading extension registration objects
-  debug.extensions: > extension registration object loading took * (glob)
-  debug.extensions: > extension foobar take a total of * to load (glob)
-  debug.extensions: extension loading complete
-  debug.extensions: loading additional extensions
-  debug.extensions: - processing 1 entries
-  debug.extensions: > loaded 0 extensions, total time * (glob)
-  debug.extensions: - loading configtable attributes
-  debug.extensions: - executing uisetup hooks
-  debug.extensions: > all uisetup took * (glob)
-  debug.extensions: - executing extsetup hooks
-  debug.extensions: > all extsetup took * (glob)
-  debug.extensions: - executing remaining aftercallbacks
-  debug.extensions: > remaining aftercallbacks completed in * (glob)
-  debug.extensions: - loading extension registration objects
-  debug.extensions: > extension registration object loading took * (glob)
-  debug.extensions: extension loading complete
-  debug.extensions: - executing reposetup hooks
-  debug.extensions:   - running reposetup for foobar
+  YYYY/MM/DD HH:MM:SS (PID)>   > uisetup for foobar took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
+  YYYY/MM/DD HH:MM:SS (PID)>   - running extsetup for foobar
+  YYYY/MM/DD HH:MM:SS (PID)>   > extsetup for foobar took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
+  YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
+  YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> > extension foobar take a total of * to load (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
+  YYYY/MM/DD HH:MM:SS (PID)> loading additional extensions
+  YYYY/MM/DD HH:MM:SS (PID)> - processing 1 entries
+  YYYY/MM/DD HH:MM:SS (PID)> > loaded 0 extensions, total time * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - loading configtable attributes
+  YYYY/MM/DD HH:MM:SS (PID)> - executing uisetup hooks
+  YYYY/MM/DD HH:MM:SS (PID)> > all uisetup took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - executing extsetup hooks
+  YYYY/MM/DD HH:MM:SS (PID)> > all extsetup took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - executing remaining aftercallbacks
+  YYYY/MM/DD HH:MM:SS (PID)> > remaining aftercallbacks completed in * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> - loading extension registration objects
+  YYYY/MM/DD HH:MM:SS (PID)> > extension registration object loading took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> extension loading complete
+  YYYY/MM/DD HH:MM:SS (PID)> - executing reposetup hooks
+  YYYY/MM/DD HH:MM:SS (PID)>   - running reposetup for foobar
   reposetup called for a
   ui == repo.ui
-  debug.extensions:   > reposetup for foobar took * (glob)
-  debug.extensions: > all reposetup took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)>   > reposetup for foobar took * (glob)
+  YYYY/MM/DD HH:MM:SS (PID)> > all reposetup took * (glob)
   Foo
 
   $ cd ..