Added time, date and total runtime information to the output by

logging system.

test/test-automation/SDL_test.c

@@ -23,6 +23,7 @@
 
 #include <stdio.h> /* printf/fprintf */
 #include <stdarg.h> /* va_list */
+#include <time.h>
 
 #include "logger.h"
 
@@ -58,7 +59,7 @@ _TestCaseQuit()
 {
 	//printf("Asserts: passed %d, failed %d\n", _testAssertsPassed, _testAssertsFailed);
 	AssertSummary(_testAssertsFailed + _testAssertsPassed,
-                  _testAssertsFailed, _testAssertsPassed);
+                  _testAssertsFailed, _testAssertsPassed, time(0));
 
 	if(_testAssertsFailed == 0 && _testAssertsPassed == 0) {
 		_testReturnValue = 2;
@@ -78,13 +79,13 @@ AssertEquals(Uint32 expected, Uint32 actual, char* message, ...)
       SDL_vsnprintf( buf, sizeof(buf), message, args );
       va_end( args );
       //printf("AssertEquals failed: expected %d, got %d; %s\n", expected, actual, buf);
-      Assert("AssertEquals", 0, buf, 0);
+      Assert("AssertEquals", 0, buf, time(0));
 
       _testReturnValue = 1;
       _testAssertsFailed++;
    } else {
       //printf("AssertEquals passed\n");
-      Assert("AssertEquals", 1, "AssertEquals passed", 0);
+      Assert("AssertEquals", 1, "AssertEquals passed", time(0));
 
       _testAssertsPassed++;
    }
@@ -102,13 +103,13 @@ AssertTrue(int condition, char *message, ...)
       va_end( args );
 
       //printf("AssertTrue failed: %s\n", buf);
-      Assert("AssertTrue", 0, buf, 0);
+      Assert("AssertTrue", 0, buf, time(0));
 
       _testReturnValue = 1;
       _testAssertsFailed++;
    } else {
      //printf("AssertTrue passed\n");
-	 Assert("AssertTrue", 1, "AssertTrue passed", 0);
+	 Assert("AssertTrue", 1, "AssertTrue passed", time(0));
      _testAssertsPassed++;
    }
 }
@@ -124,7 +125,7 @@ AssertPass(char *message, ...)
    va_end( args );
 
    //printf("AssertPass: %s\n", buf);
-   Assert("AssertPass", 1, buf, 0);
+   Assert("AssertPass", 1, buf, time(0));
 
    _testAssertsPassed++;
 }
@@ -140,7 +141,7 @@ AssertFail(char *message, ...)
    va_end( args );
 
    //printf("AssertFail: %s\n", buf);
-   Assert("AssertFail", 0, buf, 0);
+   Assert("AssertFail", 0, buf, time(0));
 
    _testAssertsFailed++;
 }

test/test-automation/logger.h

@@ -29,24 +29,25 @@
  */
 typedef	void (*RunStartedFp)(int parameterCount, char *runnerParameters[], time_t eventTime);
 typedef	void (*RunEndedFp)(int testCount, int suiteCount, int testPassCount, int testFailCount,
-                           time_t endTime, time_t totalRuntime);
+                           time_t endTime, double totalRuntime);
 
 typedef	void (*SuiteStartedFp)(const char *suiteName, time_t eventTime);
 typedef	void (*SuiteEndedFp)(int testsPassed, int testsFailed, int testsSkipped,
-		                double endTime, time_t totalRuntime);
+		                time_t endTime, double totalRuntime);
 
 typedef	void (*TestStartedFp)(const char *testName, const char *suiteName,
                               const char *testDescription, time_t startTime);
 typedef	void (*TestEndedFp)(const char *testName, const char *suiteName, int testResult,
-                            time_t endTime, time_t totalRuntime);
+                            time_t endTime, double totalRuntime);
 
 /*!
  * Note: for assertResult, non-zero == pass, zero == failure
  *
  */
-typedef	void (*AssertFp)(const char *assertName, int assertResult, const char *assertMessage,
-		            time_t eventTime);
-typedef	void (*AssertSummaryFp)(int numAsserts, int numAssertsFailed, int numAssertsPass);
+typedef	void (*AssertFp)(const char *assertName, int assertResult,
+						 const char *assertMessage, time_t eventTime);
+typedef	void (*AssertSummaryFp)(int numAsserts, int numAssertsFailed,
+								int numAssertsPass, time_t eventTime);
 
 
 typedef	void (*LogFp)(const char *logMessage, time_t eventTime);

test/test-automation/plain_logger.c

@@ -35,7 +35,7 @@ PlainRunStarted(int parameterCount, char *runnerParameters[], time_t eventTime)
 
 void
 PlainRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
-              time_t endTime, time_t totalRuntime)
+              time_t endTime, double totalRuntime)
 {
 	Output("Ran %d tests in %0.5f seconds.", testCount, totalRuntime);
 
@@ -51,7 +51,7 @@ PlainSuiteStarted(const char *suiteName, time_t eventTime)
 
 void
 PlainSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
-           double endTime, time_t totalRuntime)
+           time_t endTime, double totalRuntime)
 {
 	Output("Suite executed. %d passed, %d failed and %d skipped", testsPassed, testsFailed, testsSkipped);
 }
@@ -64,7 +64,7 @@ PlainTestStarted(const char *testName, const char *suiteName, const char *testDe
 
 void
 PlainTestEnded(const char *testName, const char *suiteName,
-          int testResult, time_t endTime, time_t totalRuntime)
+          int testResult, time_t endTime, double totalRuntime)
 {
 	Output("%s: ok", testName);
 }
@@ -78,7 +78,7 @@ PlainAssert(const char *assertName, int assertResult, const char *assertMessage,
 }
 
 void
-PlainAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass)
+PlainAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass, time_t eventTime)
 {
 	Output("Asserts:%d", numAsserts);
 }

test/test-automation/plain_logger.h

@@ -6,24 +6,24 @@
 void PlainRunStarted(int parameterCount, char *runnerParameters[], time_t eventTime);
 
 void PlainRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
-                   time_t endTime, time_t totalRuntime);
+                   time_t endTime, double totalRuntime);
 
 void PlainSuiteStarted(const char *suiteName, time_t eventTime);
 
 void PlainSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
-           double endTime, time_t totalRuntime);
+           time_t endTime, double totalRuntime);
 
 void PlainTestStarted(const char *testName, const char *suiteName,
                       const char *testDescription, time_t startTime);
 
 void PlainTestEnded(const char *testName, const char *suiteName,
-          int testResult, time_t endTime, time_t totalRuntime);
+          int testResult, time_t endTime, double totalRuntime);
 
 
 void PlainAssert(const char *assertName, int assertResult, const char *assertMessage,
        time_t eventTime);
 
-void PlainAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass);
+void PlainAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass, time_t eventTime);
 
 
 void PlainLog(const char *logMessage, time_t eventTime);

test/test-automation/runner.c

@@ -671,33 +671,44 @@ main(int argc, char *argv[])
 		return 0;
 	}
 
-	RunStarted(argc, argv, 0);
+	RunStarted(argc, argv, time(0));
 
 	char *currentSuiteName = NULL;
 
+	int suiteStartTime = SDL_GetTicks();
+
 	TestCase *testItem = NULL;
 	for(testItem = testCases; testItem; testItem = testItem->next) {
 		if(currentSuiteName == NULL) {
 			currentSuiteName = testItem->suiteName;
-			SuiteStarted(currentSuiteName, 0);
+			SuiteStarted(currentSuiteName, time(0));
 
 			testFailureCount = testPassCount = 0;
 
+			//suiteStartTime = SDL_GetTicks();
+
 			suiteCounter++;
 		}
 		else if(strncmp(currentSuiteName, testItem->suiteName, NAME_BUFFER_SIZE) != 0) {
-			SuiteEnded(testPassCount, testFailureCount, testSkipCount, 0.0f, 0);
+			const double suiteRuntime = (SDL_GetTicks() - suiteStartTime) / 1000.0f;
+
+			SuiteEnded(testPassCount, testFailureCount, testSkipCount, time(0),
+						suiteRuntime);
 
 			currentSuiteName = testItem->suiteName;
 			SuiteStarted(currentSuiteName, 0);
 
 			testFailureCount = testPassCount = 0;
 
+			//suiteStartTime = SDL_GetTicks();
+
 			suiteCounter++;
 		}
 
 		TestStarted(testItem->testName, testItem->suiteName,
-                    testItem->description, 0);
+                    testItem->description, time(0));
+
+		const Uint32 testTimeStart = SDL_GetTicks();
 
 		int retVal = ExecuteTest(testItem);
 		if(retVal) {
@@ -708,22 +719,26 @@ main(int argc, char *argv[])
 			testPassCount++;
 		}
 
-		TestEnded(testItem->testName, testItem->suiteName, retVal, 0, 0);
+		const double testTotalRuntime = (SDL_GetTicks() - testTimeStart) / 1000.0f;
+
+		TestEnded(testItem->testName, testItem->suiteName, retVal, time(0), testTotalRuntime);
 	}
 
 	if(currentSuiteName) {
 		// \todo if no test are run, this will case incorrect nesting with
 		// xml output
-		SuiteEnded(testPassCount, testFailureCount, testSkipCount, 0.0f, 0);
+		SuiteEnded(testPassCount, testFailureCount, testSkipCount, time(0),
+					(SDL_GetTicks() - suiteStartTime) / 1000.0f);
 	}
 
 	UnloadTestCases(testCases);
 	UnloadTestSuites(suites);
 
 	const Uint32 endTicks = SDL_GetTicks();
+	const double totalRunTime = (endTicks - startTicks) / 1000.0f;
 
 	RunEnded(totalTestPassCount + totalTestfailureCount, suiteCounter,
-			 totalTestPassCount, totalTestfailureCount, 0, 0);
+			 totalTestPassCount, totalTestfailureCount, time(0), totalRunTime);
 
 	return 0;
 }

test/test-automation/xml_logger.c

@@ -20,6 +20,7 @@
 
 #include <stdio.h>
 #include <stdlib.h>
+#include <time.h>
 
 #include <SDL/SDL.h>
 
@@ -43,6 +44,40 @@ char *IntToString(const int integer) {
 	return buffer;
 }
 
+/*!
+ *  Helper functions. Turns the given double value in to a string
+ *
+ *  \param integer The converted double value
+ *  \returns Given double value as string
+ */
+char *DoubleToString(const double decimal) {
+	static char buffer[sizeof(double) * 8 + 1]; // malloc might work better
+	memset(buffer, 0, sizeof(buffer));
+
+	SDL_snprintf(buffer, sizeof(buffer), "%.5f", decimal);
+
+	return buffer;
+}
+
+/*!
+ * Converts unix timestamp to it's ascii presentation
+ *
+ * \param timestamp Timestamp
+ * \return Ascii presentation
+ */
+char *TimestampToString(const time_t timestamp) {
+	static char buffer[1024];
+	//char *buffer = SDL_malloc(1024);
+	memset(buffer, 0, 1024);
+
+	time_t copy = timestamp;
+
+	struct tm *local = localtime(&copy);
+	strftime(buffer, 1024, "%a %Y-%m-%d %H:%M:%S %Z", local);
+
+	return buffer;
+}
+
 static int indentLevel;
 
 //! Constants for XMLOuputters EOL parameter
@@ -113,7 +148,7 @@ XMLRunStarted(int parameterCount, char *runnerParameters[], time_t eventTime)
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(eventTime));
+	output = XMLAddContent(TimestampToString(eventTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -124,7 +159,7 @@ XMLRunStarted(int parameterCount, char *runnerParameters[], time_t eventTime)
 
 void
 XMLRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
-            time_t endTime, time_t totalRuntime)
+            time_t endTime, double totalRuntime)
 {
 	// log suite count
 	char *output = XMLOpenElement("numSuites");
@@ -184,7 +219,7 @@ XMLRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(endTime));
+	output = XMLAddContent(TimestampToString(endTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -197,7 +232,7 @@ XMLRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(totalRuntime));
+	output = XMLAddContent(DoubleToString(totalRuntime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -205,8 +240,6 @@ XMLRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
 	XMLOutputter(--indentLevel, YES, output);
 	SDL_free(output);
 
-
-
 	output = XMLCloseDocument("testlog");
 	XMLOutputter(--indentLevel, YES, output);
 	SDL_free(output);
@@ -223,7 +256,7 @@ XMLSuiteStarted(const char *suiteName, time_t eventTime)
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(eventTime));
+	output = XMLAddContent(TimestampToString(eventTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -234,7 +267,7 @@ XMLSuiteStarted(const char *suiteName, time_t eventTime)
 
 void
 XMLSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
-           double endTime, time_t totalRuntime)
+           time_t endTime, double totalRuntime)
 {
 	// log tests passed
 	char *output = XMLOpenElement("testsPassed");
@@ -280,7 +313,7 @@ XMLSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(endTime));
+	output = XMLAddContent(TimestampToString(endTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -293,7 +326,7 @@ XMLSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(totalRuntime));
+	output = XMLAddContent(DoubleToString(totalRuntime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -308,7 +341,8 @@ XMLSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
 }
 
 void
-XMLTestStarted(const char *testName, const char *suiteName, const char *testDescription, time_t startTime)
+XMLTestStarted(const char *testName, const char *suiteName,
+			  const char *testDescription, time_t startTime)
 {
 	char * output = XMLOpenElement("test");
 	XMLOutputter(indentLevel++, YES, output);
@@ -344,7 +378,7 @@ XMLTestStarted(const char *testName, const char *suiteName, const char *testDesc
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	XMLAddContent(IntToString(startTime));
+	output = XMLAddContent(TimestampToString(startTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -355,7 +389,7 @@ XMLTestStarted(const char *testName, const char *suiteName, const char *testDesc
 
 void
 XMLTestEnded(const char *testName, const char *suiteName,
-          int testResult, time_t endTime, time_t totalRuntime)
+          int testResult, time_t endTime, double totalRuntime)
 {
 	char *output = XMLOpenElement("result");
 	XMLOutputter(indentLevel++, NO, output);
@@ -379,6 +413,33 @@ XMLTestEnded(const char *testName, const char *suiteName,
 	XMLOutputter(--indentLevel, YES, output);
 	SDL_free(output);
 
+	// log total runtime
+	output = XMLOpenElement("endTime");
+	XMLOutputter(indentLevel++, NO, output);
+	SDL_free(output);
+
+	output = XMLAddContent(TimestampToString(endTime));
+	XMLOutputter(indentLevel, NO, output);
+	SDL_free(output);
+
+	output = XMLCloseElement("endTime");
+	XMLOutputter(--indentLevel, YES, output);
+	SDL_free(output);
+
+	// log total runtime
+	output = XMLOpenElement("totalRuntime");
+	XMLOutputter(indentLevel++, NO, output);
+	SDL_free(output);
+
+	output = XMLAddContent(DoubleToString(totalRuntime));
+	XMLOutputter(indentLevel, NO, output);
+	SDL_free(output);
+
+	output = XMLCloseElement("totalRuntime");
+	XMLOutputter(--indentLevel, YES, output);
+	SDL_free(output);
+
+
 	//! \todo add endTime and TotalRuntime
 
 	output = XMLCloseElement("test");
@@ -425,7 +486,7 @@ XMLAssert(const char *assertName, int assertResult, const char *assertMessage,
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(eventTime));
+	output = XMLAddContent(TimestampToString(eventTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 
@@ -439,7 +500,8 @@ XMLAssert(const char *assertName, int assertResult, const char *assertMessage,
 }
 
 void
-XMLAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass)
+XMLAssertSummary(int numAsserts, int numAssertsFailed,
+				 int numAssertsPass, time_t eventTime)
 {
 	char *output = XMLOpenElement("assertSummary");
 	XMLOutputter(indentLevel++, YES, output);
@@ -511,7 +573,7 @@ XMLLog(const char *logMessage, time_t eventTime)
 	XMLOutputter(indentLevel++, NO, output);
 	SDL_free(output);
 
-	output = XMLAddContent(IntToString(eventTime));
+	output = XMLAddContent(TimestampToString(eventTime));
 	XMLOutputter(indentLevel, NO, output);
 	SDL_free(output);
 

test/test-automation/xml_logger.h

@@ -6,23 +6,22 @@
 void XMLRunStarted(int parameterCount, char *runnerParameters[], time_t eventTime);
 
 void XMLRunEnded(int testCount, int suiteCount, int testPassCount, int testFailCount,
-                 time_t endTime, time_t totalRuntime);
+                 time_t endTime, double totalRuntime);
 
 void XMLSuiteStarted(const char *suiteName, time_t eventTime);
 
 void XMLSuiteEnded(int testsPassed, int testsFailed, int testsSkipped,
-           double endTime, time_t totalRuntime);
+           time_t endTime, double totalRuntime);
 
 void XMLTestStarted(const char *testName, const char *suiteName, const char *testDescription, time_t startTime);
 
 void XMLTestEnded(const char *testName, const char *suiteName,
-          int testResult, time_t endTime, time_t totalRuntime);
+          int testResult, time_t endTime, double totalRuntime);
 
 void XMLAssert(const char *assertName, int assertResult, const char *assertMessage,
        time_t eventTime);
 
-void XMLAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass);
-
+void XMLAssertSummary(int numAsserts, int numAssertsFailed, int numAssertsPass, time_t eventTime);
 
 void XMLLog(const char *logMessage, time_t eventTime);