TIP #447: EXECUTION TIME VERBOSITY LEVELS IN TCLTEST::CONFIGURE 
=================================================================
 Version:      $Revision: 1.6 $
 Author:       Pietro Cerutti <gahr_at_gahr.ch>
 State:        Final
 Type:         Project
 Tcl-Version:  8.7
 Vote:         Done
 Created:      Wednesday, 20 April 2016
 URL:          https://tip.tcl-lang.org447.html
 Post-History: 

-------------------------------------------------------------------------

 ABSTRACT 
==========

 The *-verbose* option of the *tcltest::configure* command accepts a set 
 of verbosity levels to specify what pieces of information about tests 
 the user wants reported. This TIP proposes the addition of two new 
 verbosity levels to report information about the execution time of 
 tests. 

 RATIONALE 
===========

 When doing test-driven development, working on the refinement of a new 
 feature, or fixing a bug, it is very important to be able to measure 
 the effect of code changes on execution time. 

 The *tcltest* infrastructure is the testing framework used both by 
 Tcl/Tk and a number of extensions. The *tcltest* infrastructure is 
 highly configurable and allows the user to choose which information on 
 the tests being run are reported. This can be done with the *-verbose* 
 option of the *tcltest::configure* command. Verbosity levels allow to 
 report, e.g., when a test passes, is skipped, or fails. 

 A proper way to measure the time spent running each test is currently 
 missing. Scope of this TIP is to address this issue by extending the 
 set of verbosity levels accepted. 

 PROPOSAL 
==========

 The *-verbose* option of the *tcltest::configure* command is modified 
 to accept the following new verbosity levels: 

 usec (u): Report execution time of each test, in microseconds. 

 msec (m): Report the execution time of each test, in milliseconds. 

 EXAMPLE 
=========

 This example demonstrates running a subset of the Tcl test suite with 
 verbosity level *usec* (*u*): 

   $ make TESTFLAGS="-verbose u -match lsearch-1.*" test
   ...
   lsearch.test
   ++++ lsearch-1.1 took 521 us
   ++++ lsearch-1.2 took 156 us
   ++++ lsearch-1.3 took 187 us
   ++++ lsearch-1.4 took 120 us

 DISCUSSION 
============

 ADDITIONAL TIME UNITS 
-----------------------

 The implementation of additional verbosity levels to track execution 
 times in seconds, minutes, hours, and so on is trivial, but has been 
 discarded as unit or functional test are often meant to be fast. 
 Another approach would be to introduce a configurable verbosity level 
 to carry information on the time unit to be used. Examples could be 
 *time:usec*, *time:msec*, and *time:sec*. This option has also been 
 discarded because it clashes with the current approach of having 
 verbosity level strings that can be shortened to a single character. It 
 is the author's opinion that milliseconds and microseconds should 
 address most use cases. 

 WHEN TIMING SHOULD BE DISPLAYED? 
----------------------------------

 The current implementation dumps timing information before any reports 
 of success / failure. Example: 

   ---- tsv-lmdb-1.5 start
   ++++ tsv-lmdb-1.5 took 828 us
   
   
   ==== tsv-lmdb-1.5 tsv::exists - previously set exists FAILED
   ---- Result was:
   1
   ---- Result should have been (exact matching):
   0
   ==== tsv-lmdb-1.5 FAILED

 This allows for a simpler implementation that doesn't need to account 
 for the different code paths taken by *tcltest* when reporting success 
 or failure. The author doesn't have a strong opinion on this matter and 
 is open to discussion, should anybody have any counter-proposal. 

 WHAT TO PRINT? 
----------------

 The current implementation decision to print "<testname> took <amount> 
 <unit>" is arbitrary. Again, the author has no strong opinion on the 
 subject. 

 ON THE GOODNESS OF THE TIMES REPORTED 
---------------------------------------

 FV, DGP, and and DKF have raised concerns on the mailing lists on the 
 goodness of the time values reported by the *msec* and *usec* verbosity 
 levels. In particular, the problem of repeatibility of the results has 
 been mentioned, and it has been noted that while the idea is good, this 
 might not be the right tool for (the|every) job. 

 My opinion is that the tool can be useful, given that its scope is made 
 clear. I followed DGP's suggestion and added [checkin 2b96ef] an 
 explicit note in the documentation about the "modest ambitions" of this 
 enhancement. 

 REFERENCE IMPLEMENTATION 
==========================

 In the gahr-tip-447 branch. 

 COPYRIGHT 
===========

 This document has been placed in the public domain. 

-------------------------------------------------------------------------

 TIP AutoGenerator - written by Donal K. Fellows