Boost logo

Boost-Build :

From: Jurko Gospodnetiæ (jurko.gospodnetic_at_[hidden])
Date: 2007-12-23 19:04:31


   It seems that after latest 'record_time' interface fixes by Rene the
timedata test is broken for the same reason as module_action. Boost.Jam
when run by these tests no longer pipes any action output to stdout.

   A bit of playing around showed me that the difference is in how the
-d0 Boost.Jam flag is handled. Before that meant no messages except
those explicitly displayed by the build scripts - using either rules or
actions. Now it no longer displays action output. I guess this new
behavior is more in line with its description under 'bjam
--help-options' but not having the old behavior available causes
problems for automated output testing. specifies the '-d0' flag for all tests it runs and when
you replace that flag with -d1 then action output appears but so do
executed action names as well as status messages like '...found 4
targets...' or '...updated 3 targets...'.

   I looked into using the ACTION_RULE__ rule and have attached a patch
for the timedata test that makes it pass on Windows with the new -d0
semantics using that rule. Besides using the __ACTION_RULE__ rule the
test needed slight tweaks in the used regular expressions in order to
cope with additional end-of-line characters in the output.

   I found no way to avoid problems with end-of-line characters getting
messed up between each two separate action results. If I display both
the original command's output and the output received by the
__ACTION_RULE__ on Windows I get 0xd 0xa characters between them and 0xd
0xd 0xa 0xd characters after them. Most likely the first 0xd, 0xa are
added by the command and then Boost.Jam and/or Python mess up with their
end-of-line handling by twice replacing a trailing 0xa with 0xd 0xa.

   This means that there is now no way for a test to compare the
complete output constructed of multiple action results (e.g. the
module_actions test) without resorting to using a complicated regular
expression to work around extra 0xd & 0xa characters between separate
action outputs.

   My vote is that this makes action output testing way too convoluted.

   Options I can see at the moment:

   * Refactor tests not to depend on action output directly at all and
perhaps use the __ACTION_RULE__ instead. Requires fixing the end-of-line

   * Update tests to use the -d1 option and compensate for the extra
output that will result. Requires checking all tests using stdout but
should not cause false positives.

   * Update Boost.Jam to allow the old -d0 behavior - displaying
executed action outputs but no Boost.Jam progress messages like those
mentioned above. Besides reverting to the original behavior, one
suggestion is to update debug levels as follows:
      -d0 = As 'bjam help-options' says - only errors are reported. Only
rules may output and that is allowed only so build scripts could output
additional error messages. There should also be a way for scripts to
detect this level so they can avoid displaying non-error messages.
      -d1 = As -d0 was before - no Boost.Jam or Boost Build progress
messages. Only explicit build script and action output is displayed.
That would be the level used by most tests.
      -d2 = As -d1 is now - display simple Boost.Jam and Boost Build
progress messages, including names of non-quiet actions.
      -d3 = As -d2 is now...

   I prefer the third solution but am unsure whether if that could cause
too much backward compatibility problems.

   Second solution could work out as well if tests were made to run with
-d0 by default and be able to specify a different debug level if needed.
This would take just a minor in but all tests relying on
stdout would need to be rechecked for false positives such as 'expecting
some output not being displayed to mean that an action has not been run'.

   Any other thoughts on this?

   Anyway, good thing is that these are now the only test failures left
besides the one I sent related to the alias warnings defect report... :-)

   Hope this helps...

   Best regards,
     Jurko Gospodnetiæ

--- X:\Boost_Build\20071223_nightly_build\Original\boost-build\test\ 2007-12-23 15:33:26.000000000 +-0100
+++ X:\Boost_Build\20071223_nightly_build\Modified\boost-build\test\ 2007-12-23 21:21:33.000000000 +-0100
@@ -13,23 +13,29 @@
 rule time
     DEPENDS $(<) : $(>) ;
     __TIMING_RULE__ on $(>) = record_time $(<) ;
     DEPENDS all : $(<) ;
 actions time
     echo $(>) user: $(__USER_TIME__) system: $(__SYSTEM_TIME__)
     echo timed from $(>) >> $(<)
+rule display-action-output ( args * : target : command status start end user system : output ? )
+ ECHO $(output) ;
 rule record_time ( target : source : start end user system )
- ECHO record_time called: $(target) / $(source) / $(user) / $(system) ;
- __USER_TIME__ on $(target) = $(user) ;
+ __USER_TIME__ on $(target) = $(user) ;
     __SYSTEM_TIME__ on $(target) = $(system) ;
+ __ACTION_RULE__ on $(target) = display-action-output ;
 rule make
     DEPENDS $(<) : $(>) ;
@@ -44,14 +50,14 @@
 import re
 t.write('baz', 'nothing\n')
- stdout=r'bar +user: [0-9\.]+ +system: +[0-9\.]+ *$',
+ stdout=r'bar +user: [0-9.]+ +system: +[0-9.]+[ \r\n]*$',
     match = lambda actual,expected:,actual,re.DOTALL)

Boost-Build list run by bdawes at, david.abrahams at, gregod at, cpdaniel at, john at