TS_TRACE now dumps to trace buffer instead of printk

-Minor change to cxxtestgen.pl script to bump the suite name and add whitespace
- resolve conflicts in makefile and cxxtestgen.pl
- fix TS_TRACE
- add fixes from code review
- add debug messages to trace modules not finishing problem
- line over 80 chars, remove 10 sec delay
- add 5 min timeout to autocitest
- change check interval to 5 seconds instead of 30 seconds

Change-Id: I11f18fbeed007590a4ca70c45d109071474a9864
Reviewed-on: http://gfw160.austin.ibm.com:8080/gerrit/154
Tested-by: Jenkins Server
Reviewed-by: A. Patrick Williams III <iawillia@us.ibm.com>

5 files changed, 233 insertions, 214 deletions

diff --git a/src/usr/cxxtest/TestSuite.C b/src/usr/cxxtest/TestSuite.C
index 17460ae3b..99055d0cf 100755
--- a/src/usr/cxxtest/TestSuite.C
+++ b/src/usr/cxxtest/TestSuite.C
@@ -11,158 +11,156 @@
 
 namespace CxxTest
 {
-    /******************************************************************************/
-    // Globals/Constants
-    /******************************************************************************/
-
-    /**
-     * @brief global vars to keep track of unit tests.
-     *
-     * totaltests - initialized to 0, updated by reporttotaltests() below.
-     *      each test suite will call reporttotaltests after all tests have
-     *      run with the total number of tests for that suite.
-     *      Once all the testsuites have run, the global totaltests will hold
-     *      the total of number of unit test for that run.
-     *
-     *      Each unit test macro (TS_TRACE, TS_WARN, and TS_FAIL) will update
-     *      the proper variable.  At the end the unit tester will print out
-     *      the totals.
-     * // Global cxxtest values - Keep global so it can be found in syms file
-     */
-    uint64_t        g_TotalTests      =       0;
-    uint64_t        g_TraceCalls      =       0;
-    uint64_t        g_Warnings        =       0;
-    uint64_t        g_FailedTests     =       0;
-
-
-    //
-    // TestSuite members
-    //
-    TestSuite::~TestSuite() {}
-    void TestSuite::setUp() {}
-    void TestSuite::tearDown() {}
-
-    /**
-     *
-     *   @brief Implement trace action in unit tests
-     *
-     *   @param [in] pointer to filename  (not used right now )
-     *   @param [in] line number
-     *   @param [in] trace message
-     *
-     *   @return void
-     *
-     */
-    void doTrace( const char *file, unsigned line, const char *message )
-    {
-        // tracker().trace( file, line, message );
-        printk("TRACE: %s %u %s\n", file, line, message);
-        __sync_add_and_fetch( &g_TraceCalls, 1 );
-    }
-
-    /**
-     *
-     *   @brief Implement warn action in unit tests
-     *
-     *   @param [in] pointer to filename  (not used right now )
-     *   @param [in] line number
-     *   @param [in] warning message
-     *
-     *   @return void
-     *
-     */
-    void doWarn( const char *file, unsigned line, const char *message )
-    {
-        // tracker().warning( file, line, message );
-        printk("WARN: %s %u %s\n", file, line, message);
-        __sync_add_and_fetch( &g_Warnings, 1 );
-    }
-
-    /**
-     *   @brief Implement Fail action in unit tests
-     *
-     *   @param [in] pointer to filename  (not used right now )
-     *   @param [in] line number
-     *   @param [in] failure message
-     *
-     *   @return void
-     */
-
-    void doFailTest( const char *file, unsigned line, const char *message )
-    {
-        // tracker().failedTest( file, line, message );
-        printk("FAIL: %s %u %s\n", file, line, message);
-        __sync_add_and_fetch( &g_FailedTests, 1 );
-    }
-
-    /**
-     *  @brief Report total number of unit tests in a test suite
-     *
-     *  A unit test suite will call this to report how many tests
-     *  it has.  The call itself is autogenerated
-     *
-     *  @param [in] pointer to filename  (not used right now )
-     *  @param [in] line number
-     *  @param [in] trace message
-     *
-     *  @return void
-     */
-    void    reportTotalTests( const char *suitename, uint64_t numtests )
-    {
-
-        //  $$TODO do nothing with the suite name for now, later it may be useful
-        __sync_add_and_fetch( &g_TotalTests, numtests );
-
-        return;
-    }
-
-    /**
-     * @brief   accessor to read global totaltests var
-     * @TODO  make these readonly accessors
-     *
-     * @return  number of total tests
-     */
-    uint64_t    getTotalTests(void)
-    {
-
-        return  g_TotalTests;
-    }
-
-    /**
-     * @brief   accessor to read global failedtests var
-     * @TODO  make these readonly accessors
-     *
-     * @return  total number off failures executed
-     */
-    uint64_t    getFailedTests(void)
-    {
-
-        return  g_FailedTests;
-    }
-
-    /**
-     * @brief   accessor to read global warnings var
-     * @TODO  make these readonly accessors
-     *
-     * @return  total number of warnings executed
-     */
-    uint64_t    getWarnings(void)
-    {
-
-        return  g_Warnings;
-    }
-
-    /**
-     * @brief   accessor to read global tracecalls var
-     * @TODO  make these readonly accessors
-     *
-     * @return  total number of trace calls executed
-     */
-    uint64_t    getTraceCalls(void)
-    {
-
-        return  g_TraceCalls;
-    }
+/******************************************************************************/
+// Globals/Constants
+/******************************************************************************/
+
+/**
+ * @brief global vars to keep track of unit tests.
+ *
+ * totaltests - initialized to 0, updated by reporttotaltests() below.
+ *      each test suite will call reporttotaltests after all tests have
+ *      run with the total number of tests for that suite.
+ *      Once all the testsuites have run, the global totaltests will hold
+ *      the total of number of unit test for that run.
+ *
+ *      Each unit test macro (TS_TRACE, TS_WARN, and TS_FAIL) will update
+ *      the proper variable.  At the end the unit tester will print out
+ *      the totals.
+ * // Global cxxtest values - Keep global so it can be found in syms file
+ */
+uint64_t        g_TotalTests      =       0;
+uint64_t        g_TraceCalls      =       0;
+uint64_t        g_Warnings        =       0;
+uint64_t        g_FailedTests     =       0;
+
+
+//
+// TestSuite members
+//
+TestSuite::~TestSuite() {}
+void TestSuite::setUp() {}
+void TestSuite::tearDown() {}
+
+/**
+ *
+ *   @brief Implement trace action in unit tests
+ *
+ *   @return void
+ *
+ */
+void doTrace( void )
+{
+
+    __sync_add_and_fetch( &g_TraceCalls, 1 );
+
+    return;
+}
+
+/**
+ *
+ *   @brief Implement warn action in unit tests
+ *
+ *   @param [in] pointer to filename  (not used right now )
+ *   @param [in] line number
+ *   @param [in] warning message
+ *
+ *   @return void
+ *
+ */
+void doWarn( const char *file, unsigned line, const char *message )
+{
+
+    printk("WARN: %s %u %s\n", file, line, message);
+    __sync_add_and_fetch( &g_Warnings, 1 );
+}
+
+/**
+ *   @brief Implement Fail action in unit tests
+ *
+ *   @param [in] pointer to filename  (not used right now )
+ *   @param [in] line number
+ *   @param [in] failure message
+ *
+ *   @return void
+ */
+
+void doFailTest( const char *file, unsigned line, const char *message )
+{
+
+    printk("FAIL: %s %u %s\n", file, line, message);
+    __sync_add_and_fetch( &g_FailedTests, 1 );
+}
+
+/**
+ *  @brief Report total number of unit tests in a test suite
+ *
+ *  A unit test suite will call this to report how many tests
+ *  it has.  The call itself is autogenerated
+ *
+ *  @param [in] pointer to filename  (not used right now )
+ *  @param [in] line number
+ *  @param [in] trace message
+ *
+ *  @return void
+ */
+void    reportTotalTests( const char *suitename, uint64_t numtests )
+{
+
+    //  $$TODO do nothing with the suite name for now, later it may be useful
+    __sync_add_and_fetch( &g_TotalTests, numtests );
+    printk( "%s completed %ld tests\n", suitename, numtests);
+
+    return;
+}
+
+/**
+ * @brief   accessor to read global totaltests var
+ * @TODO  make these readonly accessors
+ *
+ * @return  number of total tests
+ */
+uint64_t    getTotalTests(void)
+{
+
+    return  g_TotalTests;
+}
+
+/**
+ * @brief   accessor to read global failedtests var
+ * @TODO  make these readonly accessors
+ *
+ * @return  total number off failures executed
+ */
+uint64_t    getFailedTests(void)
+{
+
+    return  g_FailedTests;
+}
+
+/**
+ * @brief   accessor to read global warnings var
+ * @TODO  make these readonly accessors
+ *
+ * @return  total number of warnings executed
+ */
+uint64_t    getWarnings(void)
+{
+
+    return  g_Warnings;
+}
+
+/**
+ * @brief   accessor to read global tracecalls var
+ * @TODO  make these readonly accessors
+ *
+ * @return  total number of trace calls executed
+ */
+uint64_t    getTraceCalls(void)
+{
+
+    return  g_TraceCalls;
+}
 
 };
 
diff --git a/src/usr/cxxtest/cxxtestexec.C b/src/usr/cxxtest/cxxtestexec.C
index b4785cbc5..5efb1827e 100644
--- a/src/usr/cxxtest/cxxtestexec.C
+++ b/src/usr/cxxtest/cxxtestexec.C
@@ -2,6 +2,7 @@
 #include <sys/task.h>
 #include <string.h>
 #include <kernel/console.H>
+#include <sys/time.h>
 
 namespace CxxTest
 {
@@ -27,6 +28,8 @@ void _start(void*)
             if (NULL != vfsItr->start)
             {
                 __sync_add_and_fetch(&CxxTest::g_ModulesStarted, 1);
+                printk( "running %s, ModulesStarted=0x%ld\n",
+                        vfsItr->module, CxxTest::g_ModulesStarted );
                 task_exec(vfsItr->module, NULL);
             }
         }
@@ -34,6 +37,7 @@ void _start(void*)
     }
 
     __sync_add_and_fetch(&CxxTest::g_ModulesCompleted, 1);
+    printk( " ModulesCompleted=0x%ld\n", CxxTest::g_ModulesCompleted );
 
     task_end();
 }
diff --git a/src/usr/cxxtest/cxxtestgen.pl b/src/usr/cxxtest/cxxtestgen.pl
index 24b722163..701c98633 100755
--- a/src/usr/cxxtest/cxxtestgen.pl
+++ b/src/usr/cxxtest/cxxtestgen.pl
@@ -1,9 +1,9 @@
 #!/usr/bin/perl -w
 #
-#	Change History:
-#	mww 2011-05-10	simplify for sprint1 - stuff for later is commented out with "##"
-#					modified from /esw/fips730/Builds/built/tools/x86/cxxtestgen.pl	
-#					(actually this looks the same as the latest on sourceforge)
+#       Change History:
+#       mww 2011-05-10  simplify for sprint1 - stuff for later is commented out with "##"
+#                                       modified from /esw/fips730/Builds/built/tools/x86/cxxtestgen.pl
+#                                       (actually this looks the same as the latest on sourceforge)
 #
 use strict;
 use Getopt::Long;
@@ -53,26 +53,26 @@ my @headers = ();
 sub parseCommandline() {
   @ARGV = expandWildcards(@ARGV);
   GetOptions( 'version'        => \&printVersion,
-	      'output=s'       => \$output,
-	      'template=s'     => \$template,
-	      'runner=s'       => \$runner,
-	      'gui=s',         => \$gui,
-	      'error-printer'  => sub { $runner = 'ErrorPrinter'; $haveStd = 1; },
-	      'abort-on-fail'  => \$abortOnFail,
-	      'have-eh'        => \$haveEh,
-	      'no-eh'          => \$noEh,
-	      'have-std'        => \$haveStd,
-	      'no-std'          => \$noStd,
-	      'include=s'      => \@headers,
-	      'root'           => \$root,
-	      'part'           => \$part,
-	      'no-static-init' => \$noStaticInit,
-	      'factor'         => \$factor,
-	      'longlong:s'     => \$longlong,
-	      'hostboot'       => \$hostboot,
-	      'debug'          => \$debug
-	    ) or usage();
-	
+              'output=s'       => \$output,
+              'template=s'     => \$template,
+              'runner=s'       => \$runner,
+              'gui=s',         => \$gui,
+              'error-printer'  => sub { $runner = 'ErrorPrinter'; $haveStd = 1; },
+              'abort-on-fail'  => \$abortOnFail,
+              'have-eh'        => \$haveEh,
+              'no-eh'          => \$noEh,
+              'have-std'        => \$haveStd,
+              'no-std'          => \$noStd,
+              'include=s'      => \@headers,
+              'root'           => \$root,
+              'part'           => \$part,
+              'no-static-init' => \$noStaticInit,
+              'factor'         => \$factor,
+              'longlong:s'     => \$longlong,
+              'hostboot'       => \$hostboot,
+              'debug'          => \$debug
+            ) or usage();
+
   scalar @ARGV or $root or usage();
 
   if ( defined($noStaticInit) && (defined($root) || defined($part)) ) {
@@ -135,9 +135,9 @@ sub scanInputFile($) {
 
     if ( $suite ) {
       if ( lineBelongsToSuite( $suite, $., $line ) ) {
-	scanLineForTest( $., $line );
-	scanLineForCreate( $., $line );
-	scanLineForDestroy( $., $line );
+        scanLineForTest( $., $line );
+        scanLineForCreate( $., $line );
+        scanLineForDestroy( $., $line );
       }
     }
   }
@@ -189,13 +189,13 @@ sub startSuite($$$$) {
   my ($name, $file, $line, $generated) = @_;
   closeSuite();
   $suite = { 'name' => $name,
-	     'file' => $file,
-	     'line' => $line,
-	     'generated' => $generated,
-	     'create' => 0,
-	     'destroy' => 0,
-	     'tests' => [],
-	     'lines' => [] };
+             'file' => $file,
+             'line' => $line,
+             'generated' => $generated,
+             'create' => 0,
+             'destroy' => 0,
+             'tests' => [],
+             'lines' => [] };
 }
 
 sub lineStartsBlock($) {
@@ -213,7 +213,7 @@ sub scanLineForTest($$) {
 sub addTest($$$) {
   my ($name, $line) = @_;
   $test = { 'name' => $name,
-	    'line' => $line };
+            'line' => $line };
   push @{suiteTests()}, $test;
 }
 
@@ -516,7 +516,7 @@ sub writeDynamicDescription() {
   if ( !$noStaticInit ) {
     printf "( %s, %s, \"%s\", %s, %s, %s, %s )",
       fileString(), $suite->{'line'}, suiteName(), testList(),
-	suiteObject(), suiteCreateLine(), suiteDestroyLine();
+        suiteObject(), suiteCreateLine(), suiteDestroyLine();
   }
   print ";\n\n";
 }
@@ -543,17 +543,17 @@ sub writeInitialize() {
     if ( dynamicSuite() ) {
       printf "  %s = 0;\n", suiteObject();
       printf "  %s.initialize( %s, %s, \"%s\", %s, %s, %s, %s );\n",
-	suiteDescription(), fileString(), $suite->{'line'}, suiteName(), testList(),
-	  suiteObject(), suiteCreateLine(), suiteDestroyLine();
+        suiteDescription(), fileString(), $suite->{'line'}, suiteName(), testList(),
+          suiteObject(), suiteCreateLine(), suiteDestroyLine();
     } else {
       printf "  %s.initialize( %s, %s, \"%s\", %s, %s );\n",
-	suiteDescription(), fileString(), $suite->{'line'}, suiteName(), suiteObject(), testList();
+        suiteDescription(), fileString(), $suite->{'line'}, suiteName(), suiteObject(), testList();
     }
 
     foreach (@{suiteTests()}) {
       $test = $_;
       printf "  testDescription_%s_%s.initialize( %s, %s, %s, \"%s\" );\n",
-	suiteName(), testName(), testList(), suiteDescription(), testLine(), testName();
+        suiteName(), testName(), testList(), suiteDescription(), testLine(), testName();
     }
   }
   print " }\n";
@@ -653,8 +653,9 @@ sub writeHostBootSuites() {
     }
 
     ##  declare and instantiate a new instance of the suite
-    print   "\t// Test Suite #1: ", suiteName(), "\n";
+    print   "\t// Test Suite ", $suitecount, ": " , suiteName(), "\n";
     print   "\tprintk(\"Executing test suite ", suiteName(), ".\\n\");\n";
+    print   "\tTRACDCOMP( g_trac_test, \"Execute ", suiteName(), ".\");\n";
     print   "\t", suiteName(), "\t*", $suitevar, "   =   new ", suiteName(), ";\n";
 
     ##if ( $suite->{'generated'} ) { generateSuite(); }
@@ -673,22 +674,25 @@ sub writeHostBootSuites() {
     print   "\n";
     ##  delete the suite instance
     print   "\tdelete   ", $suitevar, ";\n";
-    
+
     print   "\n";
     print "\tCxxTest::reportTotalTests( \"", suiteName(), "\", $testcount );\n";
-    
+    print   "\n";
+
     $suitecount++;                            # bump to the next suite
   }
 }
 
 ##
-##  mww for HostBoot we write a _start() routine, there is no main()
+##  For HostBoot we write a _start() routine, there is no main()
 ##
 sub write_start() {
 
   print   "\n";
   print   "trace_desc_t *g_trac_test = NULL;\n";
-  print   "TRAC_INIT(&g_trac_test, \"", suiteName(), "\", 4096);\n";
+##  Use same trace buffer for all unit tests, i.e. "UNIT_TEST"  
+##  print   "TRAC_INIT(&g_trac_test, \"", suiteName(), "\", 4096);\n";
+  print   "TRAC_INIT(&g_trac_test, \"", "UNIT_TEST", "\", 4096);\n";
 
 
   print   "\n\n";
diff --git a/src/usr/example/test/exampletest.H b/src/usr/example/test/exampletest.H
index f6cad9863..1df27a52e 100644
--- a/src/usr/example/test/exampletest.H
+++ b/src/usr/example/test/exampletest.H
@@ -6,7 +6,7 @@
  *
  *  @brief Example for people to use when writing test cases for their module.
  *  @todo  add more doxygen blocks
-*/
+ */
 
 #include <cxxtest/TestSuite.H>
 #include <example/example.H>
@@ -18,34 +18,35 @@ public:
 
 
     /**
-     * @test TS_WARN will run if the example1_function FAILS
-     *      */
+     * @test TS_WARN will run if the testExampleWarn_function FAILS
+     */
     void testExampleWarn(void)
     {
         uint64_t    l_rc = 0;
         l_rc = example1_function();
         if(l_rc)
         {
-                TS_WARN("Warning, Call to example1_function1 returned bad value.\n");
+            TS_WARN("Warning, Call to testExampleWarn returned bad value.\n");
         }
     }
 
 
     /**
-          * @test TS_TRACE will run if the example1_function FAILS
-          *      */
+     * @test TS_TRACE will run if the testExampleTrace function FAILS
+     *
+     */
     void testExampleTrace(void)
     {
         uint64_t    l_rc = 0;
         l_rc = example1_function();
         if(l_rc)
         {
-                TS_TRACE("Tracing something in example1_function1\n");
+            TS_TRACE("Tracing a failure in testExampleTrace function1\n");
         }
     }
 
     /**
-          * @test TS_FAIL will run if the example1_function FAILS
+     * @test TS_FAIL will run if the testExampleFail function FAILS
      */
     void testExampleFail(void)
     {
@@ -53,11 +54,11 @@ public:
         l_rc = example1_function();
         if(l_rc)
         {
-                TS_FAIL("Call to example1_function1 failed!\n");
+            TS_FAIL("Call to testExampleFail failed!\n");
         }
     }
     /**
-          * @test this will always run TS_FAIL
+     * @test this will always run TS_FAIL
      */
     void testExampleForceFail(void)
     {
@@ -66,7 +67,7 @@ public:
     }
 
     /**
-          * @test this will always run TS_WARN
+     * @test this will always run TS_WARN
      */
     void testExampleForceWarn(void)
     {
@@ -74,12 +75,20 @@ public:
         TS_WARN("Run TS_WARN() as part of the example test\n" );
     }
     /**
-          * @test this will always run TS_WARN
+     * @test this will always run TS_TRACE
      */
     void testExampleForceTrace(void)
     {
+        uint32_t i_32test   =   0xdeadbeef;
+        uint64_t i_64test   =   0xbadc0ffee0ddf00d;
 
         TS_TRACE("Run TS_TRACE() as part of the example test\n" );
+
+        TS_TRACE("Run TS_TRACE() with one print parameter: %d\n", 5 );
+
+        TS_TRACE("Run TS_TRACE() with 2 parameters: 0x%x 0x%x \n", i_32test, 0x78 );
+
+        TS_TRACE("Run TS_TRACE() with 3 parameters:  %d, 0x%llx, %p", 328, i_64test, &i_64test );
     }
 
 
diff --git a/src/usr/initservice/test/initservicetest.H b/src/usr/initservice/test/initservicetest.H
index 3edfa2885..d05dbd583 100644
--- a/src/usr/initservice/test/initservicetest.H
+++ b/src/usr/initservice/test/initservicetest.H
@@ -95,7 +95,6 @@ public:
         if ( (int16_t)tidrc < 0  )
         {
             TS_TRACE( "SUCCESS: startTask returned an errorlog.\n");
-            //  @todo   dump error log to trace?
         }
         else
         {
@@ -127,7 +126,6 @@ public:
         if ( (int16_t)tidrc >= 0  )
         {
             TS_TRACE( "SUCCESS: startTask returned OK.\n");
-            //  @todo   dump error log to trace?
         }
         else
         {
@@ -160,7 +158,6 @@ public:
         if ( (int16_t)tidrc < 0  )
         {
             TS_TRACE( "SUCCESS: startTask returned an error log.\n");
-            //  @todo   dump error log to trace?
         }
         else
         {
@@ -192,6 +189,10 @@ public:
         {
             TS_FAIL( "ERROR:  expected the NULL errlHndl_t to stay NULL\n");
         }
+        else
+        {
+            TS_TRACE( "SUCCESS: reportError returned OK.");
+        }
 
         return;
     }
@@ -225,11 +226,14 @@ public:
         {
             TS_FAIL( "ERROR: reportError did not delete the errlHndl_t handle!\n" );
         }
-
-
+        else
+        {
+            TS_TRACE( "SUCCESS: reportError returned OK.");
+        }
 
         return;
     }
+
 };  // class InitServiceTest