src/base/trace.test.cc - public/gem5 - Git at Google

 /*
  * Copyright (c) 2021 Daniel R. Carvalho
  * All rights reserved
  *
  * Redistribution and use in source and binary forms, with or without
  * modification, are permitted provided that the following conditions are
  * met: redistributions of source code must retain the above copyright
  * notice, this list of conditions and the following disclaimer;
  * redistributions in binary form must reproduce the above copyright
  * notice, this list of conditions and the following disclaimer in the
  * documentation and/or other materials provided with the distribution;
  * neither the name of the copyright holders nor the names of its
  * contributors may be used to endorse or promote products derived from
  * this software without specific prior written permission.
  *
  * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
  * "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
  * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
  * A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
  * OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
  * SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
  * LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
  * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
  * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
  * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
  * OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
  */

 #include <gtest/gtest.h>

 #include <sstream>
 #include <string>

 #include "base/gtest/cur_tick_fake.hh"
 #include "base/gtest/logging.hh"
 #include "base/named.hh"
 #include "base/trace.hh"

 using namespace gem5;

 // In test SetGetLogger this logger will be assigned to be the one returned
 // by Tracer::getDebugLogger(). All tests before that test should assume
 // that getDebugLogger() returns a cerr-based logger, and all tests after
 // that test should assume that this logger is returned
 std::stringstream ss;
 Trace::OstreamLogger main_logger(ss);

 // Instantiate the mock class to have a valid curTick of 0
 GTestTickHandler tickHandler;

 namespace gem5
 {
 namespace debug
 {
 /** Debug flag used for the tests in this file. */
 SimpleFlag TraceTestDebugFlag("TraceTestDebugFlag",
     "Exclusive debug flag for the trace tests");
 } // namespace debug
 } // namespace gem5

 /** @return The ostream as a std::string. */
 std::string
 getString(std::ostream &os)
 {
     auto buf = os.rdbuf();
     std::ostringstream oss;
     oss << buf;
     return oss.str();
 }

 /** @return The logger's ostream as a std::string. */
 std::string
 getString(Trace::Logger *logger)
 {
     return getString(logger->getOstream());
 }

 /** Test creating a simple log message. */
 TEST(TraceTest, LogSimpleMessage)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.logMessage(Tick(100), "", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Test message");
 }

 /** Test creating a simple log message with a name. */
 TEST(TraceTest, LogMessageName)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 }

 /** Test that when the tick is set to MaxTick it is not printed. */
 TEST(TraceTest, LogMessageMaxTick)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.logMessage(MaxTick, "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "Foo: Test message");
 }

 /** Test that by default the flag is not printed. */
 TEST(TraceTest, LogMessageFlagDisabled)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.logMessage(Tick(100), "Foo", "Bar", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 }

 /**
  * Test creating a simple log message without tick information and that
  * enabling and disabling format flags work.
  */
 TEST(TraceTest, LogMessageTickDisabledAndEnableDisable)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");

     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("FmtTicksOff", true));

     logger.logMessage(Tick(200), "Foo", "", "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(&logger), "Foo: Test message");
 #else
     ASSERT_EQ(getString(&logger), "    200: Foo: Test message");
 #endif

     debug::changeFlag("FmtTicksOff", false);
     Trace::disable();

     logger.logMessage(Tick(300), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    300: Foo: Test message");
 }

 /**
  * Test creating a full log message to verify expected order of appearance.
  * This does not include the backtrace.
  */
 TEST(TraceTest, LogMessageFlagEnabled)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));

     logger.logMessage(Tick(100), "Foo", "Bar", "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(&logger), "    100: Bar: Foo: Test message");
 #else
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 #endif

     debug::changeFlag("FmtFlag", false);
     Trace::disable();
 }

 /** Test that log messages are not displayed for ignored objects (single). */
 TEST(TraceTest, LogMessageIgnoreOne)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     ObjectMatch ignore_foo("Foo");
     ObjectMatch ignore_bar("Bar");

     // Ignore foo
     logger.setIgnore(ignore_foo);
     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
     logger.logMessage(Tick(100), "Bar", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Bar: Test message");

     // Make sure that when setting a new ignore the old ignores are not kept
     logger.setIgnore(ignore_bar);
     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
     logger.logMessage(Tick(100), "Bar", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
 }

 /** Test that log messages are not displayed for ignored objects (multiple). */
 TEST(TraceTest, LogMessageIgnoreMultiple)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     ObjectMatch ignore_foo("Foo");
     ObjectMatch ignore_bar("Bar");
     ObjectMatch ignore_thy("Thy");

     // Ignore foo and bar
     logger.setIgnore(ignore_foo);
     logger.addIgnore(ignore_bar);
     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
     logger.logMessage(Tick(100), "Bar", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
     logger.logMessage(Tick(100), "Thy", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Thy: Test message");

     // Make sure that when setting a new ignore, the old sub-ignores
     // are not kept
     logger.setIgnore(ignore_thy);
     logger.logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
     logger.logMessage(Tick(100), "Bar", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Bar: Test message");
     logger.logMessage(Tick(100), "Thy", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
 }

 /** Test that dumping for an ignored name does not log anything. */
 TEST(TraceTest, DumpIgnored)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     ObjectMatch ignore_foo("Foo");
     logger.setIgnore(ignore_foo);
     std::string message = "Test message";
     logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "");
     ASSERT_EQ(getString(&logger), "");
 }

 /**
  * Test that a regular dump will change the message so that it contains both
  * the hex and char representation of every byte. There is a space between
  * every 8 bytes. For each 16-byte line of a message the order of appearance is
  *   <byte number> <2 spaces> <8 spaced bytes> <1 space> <8 spaced bytes>
  *   <3-spaces missing to fill 16 bytes> <1 space> <16 bytes as chars> <\n>
  */
 TEST(TraceTest, DumpSimple)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     std::string message = "Test message";
     logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "Bar");
 #if TRACING_ON
     ASSERT_EQ(getString(&logger),
         // logMessage prefix
         "    100: Bar: Foo: "
         // Byte number + 2 spaces
         "00000000  "
         // 8 bytes + 1 space + 4 bytes + ((16 - 12) * 3) spaces
         "54 65 73 74 20 6d 65 73  73 61 67 65              "
         // 1 space + 12 chars + \n
         " Test message\n");
 #else
     ASSERT_EQ(getString(&logger),
         // logMessage prefix
         "    100: Foo: "
         // Byte number + 2 spaces
         "00000000  "
         // 8 bytes + 1 space + 4 bytes + ((16 - 12) * 3) spaces
         "54 65 73 74 20 6d 65 73  73 61 67 65              "
         // 1 space + 12 chars + \n
         " Test message\n");
 #endif
     debug::changeFlag("FmtFlag", false);
     Trace::disable();
 }

 /**
  * Test that a regular dump will change the message so that it contains both
  * the hex and char representation of every byte, for a multi-line message.
  */
 TEST(TraceTest, DumpMultiLine)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     std::string message =
         "This is a very long line that will span over multiple lines";
     logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "");
     ASSERT_EQ(getString(&logger),
         "    100: Foo: 00000000  "
         "54 68 69 73 20 69 73 20  61 20 76 65 72 79 20 6c   This is a very l\n"
         "    100: Foo: 00000010  "
         "6f 6e 67 20 6c 69 6e 65  20 74 68 61 74 20 77 69   ong line that wi\n"
         "    100: Foo: 00000020  "
         "6c 6c 20 73 70 61 6e 20  6f 76 65 72 20 6d 75 6c   ll span over mul\n"
         "    100: Foo: 00000030  "
         "74 69 70 6c 65 20 6c 69  6e 65 73                  tiple lines\n");
 }

 /**
  * Test that when no logger exists a logger is created redirecting to cerr.
  * This is the only test that uses cerr. All other test will use main_logger.
  */
 TEST(TraceTest, DISABLED_GetNullLogger)
 {
     Trace::Logger *logger = Trace::getDebugLogger();
     ASSERT_FALSE(logger == nullptr);

     gtestLogOutput.str("");
     logger->logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(gtestLogOutput.str(), "    100: Foo: Test message");
 }

 /** Test that the logger is set properly. */
 TEST(TraceTest, SetGetLogger)
 {
     // NOTE: From now on getDebugLogger will use main_logger to avoid
     // having to check cerr. This assumes that tests are run in the order
     // they appear from line 1 to the last line of this file.
     Trace::setDebugLogger(&main_logger);

     // Set message with local variable, and retrieve the string with
     // the debug-logger getter
     main_logger.logMessage(Tick(100), "Foo", "", "Test message");
     auto logger_from_getter = Trace::getDebugLogger();
     ASSERT_EQ(getString(logger_from_getter), "    100: Foo: Test message");
 }

 /** Test that output() gets the ostream of the current debug logger. */
 TEST(TraceTest, Output)
 {
     Trace::getDebugLogger()->logMessage(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(Trace::output()), "    100: Foo: Test message");
 }

 /** Test dprintf_flag with ignored name. */
 TEST(TraceTest, DprintfFlagIgnore)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     ObjectMatch ignore_foo("Foo");
     logger.setIgnore(ignore_foo);
     logger.dprintf_flag(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "");
 }

 /** Test dprintf_flag with zero args. */
 TEST(TraceTest, DprintfFlagZeroArgs)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.dprintf_flag(Tick(100), "Foo", "", "Test message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 }

 /** Test dprintf_flag with one arg. */
 TEST(TraceTest, DprintfFlagOneArg)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.dprintf_flag(Tick(100), "Foo", "", "Test %s", "message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 }

 /** Test dprintf_flag with multiple args. */
 TEST(TraceTest, DprintfFlagMultipleArgs)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     logger.dprintf_flag(Tick(100), "Foo", "", "Test %s %c %d %x",
         "message", 'A', 217, 0x30);
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message A 217 30");
 }

 /** Test dprintf_flag with flag. */
 TEST(TraceTest, DprintfFlagEnabled)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     logger.dprintf_flag(Tick(100), "Foo", "Bar", "Test %s", "message");
 #if TRACING_ON
     ASSERT_EQ(getString(&logger), "    100: Bar: Foo: Test message");
 #else
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
 #endif
     debug::changeFlag("FmtFlag", false);
     Trace::disable();
 }

 /** Test dprintf with ignored name. */
 TEST(TraceTest, DprintfIgnore)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     ObjectMatch ignore_foo("Foo");
     logger.setIgnore(ignore_foo);
     logger.dprintf(Tick(100), "Foo", "Test message");
     ASSERT_EQ(getString(&logger), "");
 }

 /** Test that dprintf does not have a flag. */
 TEST(TraceTest, DprintfEnabled)
 {
     std::stringstream ss;
     Trace::OstreamLogger logger(ss);

     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     logger.dprintf(Tick(100), "Foo", "Test %s", "message");
     ASSERT_EQ(getString(&logger), "    100: Foo: Test message");
     debug::changeFlag("FmtFlag", false);
     Trace::disable();
 }

 /** Test that dprintf is just a flagless wrapper for dprintf_flag. */
 TEST(TraceTest, DprintfWrapper)
 {
     std::stringstream ss, ss_flag;
     Trace::OstreamLogger logger(ss);
     Trace::OstreamLogger logger_flag(ss_flag);

     logger.dprintf(Tick(100), "Foo", "Test %s %c %d %x",
         "message", 'A', 217, 0x30);
     logger_flag.dprintf_flag(Tick(100), "Foo", "", "Test %s %c %d %x",
         "message", 'A', 217, 0x30);
     ASSERT_EQ(getString(&logger), getString(&logger_flag));
 }

 /** Test DDUMP with tracing on. */
 TEST(TraceTest, MacroDDUMP)
 {
     StringWrap name("Foo");
     std::string message = "Test message";

     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     DDUMP(TraceTestDebugFlag, message.c_str(), message.size());
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()),
         "      0: TraceTestDebugFlag: Foo: 00000000  "
         "54 65 73 74 20 6d 65 73  73 61 67 65               Test message\n");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
     DDUMP(TraceTestDebugFlag, message.c_str(), message.size());
     ASSERT_EQ(getString(Trace::output()), "");
 }

 /** Test DPRINTF with tracing on. */
 TEST(TraceTest, MacroDPRINTF)
 {
     StringWrap name("Foo");

     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     DPRINTF(TraceTestDebugFlag, "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()),
         "      0: TraceTestDebugFlag: Foo: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
     DPRINTF(TraceTestDebugFlag, "Test message");
     ASSERT_EQ(getString(Trace::output()), "");
 }

 /** Test DPRINTFS with tracing on. */
 TEST(TraceTest, MacroDPRINTFS)
 {
     Named named("Foo");
 #if TRACING_ON
     Named *named_ptr = &named;
 #endif

     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
 #if TRACING_ON
     DPRINTFS(TraceTestDebugFlag, named_ptr, "Test message");
     ASSERT_EQ(getString(Trace::output()),
         "      0: TraceTestDebugFlag: Foo: Test message");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
 #if TRACING_ON
     DPRINTFS(TraceTestDebugFlag, named_ptr, "Test message");
     ASSERT_EQ(getString(Trace::output()), "");
 #endif
 }

 /** Test DPRINTFR with tracing on. */
 TEST(TraceTest, MacroDPRINTFR)
 {
     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     DPRINTFR(TraceTestDebugFlag, "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()), "TraceTestDebugFlag: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
     DPRINTFR(TraceTestDebugFlag, "Test message");
     ASSERT_EQ(getString(Trace::output()), "");
 }

 /** Test DPRINTFN with tracing on. */
 TEST(TraceTest, MacroDPRINTFN)
 {
     StringWrap name("Foo");
     DPRINTFN("Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()), "      0: Foo: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif
 }

 /** Test DPRINTFNR with tracing on. */
 TEST(TraceTest, MacroDPRINTFNR)
 {
     DPRINTFNR("Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()), "Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif
 }

 /** Test DPRINTF_UNCONDITIONAL with tracing on. */
 TEST(TraceTest, MacroDPRINTF_UNCONDITIONAL)
 {
     StringWrap name("Foo");

     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     DPRINTF_UNCONDITIONAL(TraceTestDebugFlag, "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()),
         "      0: TraceTestDebugFlag: Foo: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
     DPRINTF_UNCONDITIONAL(TraceTestDebugFlag, "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()), "      0: Foo: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif
 }

 /**
  * Test that there is a global name() to fall through when a locally scoped
  * name() is not defined.
  */
 TEST(TraceTest, GlobalName)
 {
     // Flag enabled
     Trace::enable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
     EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
     DPRINTF(TraceTestDebugFlag, "Test message");
 #if TRACING_ON
     ASSERT_EQ(getString(Trace::output()),
         "      0: TraceTestDebugFlag: global: Test message");
 #else
     ASSERT_EQ(getString(Trace::output()), "");
 #endif

     // Flag disabled
     Trace::disable();
     EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
     DPRINTF(TraceTestDebugFlag, "Test message");
     ASSERT_EQ(getString(Trace::output()), "");
 }
	/*
	* Copyright (c) 2021 Daniel R. Carvalho
	* All rights reserved
	*
	* Redistribution and use in source and binary forms, with or without
	* modification, are permitted provided that the following conditions are
	* met: redistributions of source code must retain the above copyright
	* notice, this list of conditions and the following disclaimer;
	* redistributions in binary form must reproduce the above copyright
	* notice, this list of conditions and the following disclaimer in the
	* documentation and/or other materials provided with the distribution;
	* neither the name of the copyright holders nor the names of its
	* contributors may be used to endorse or promote products derived from
	* this software without specific prior written permission.
	*
	* THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
	* "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
	* LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
	* A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
	* OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
	* SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
	* LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
	* DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
	* THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
	* (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
	* OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
	*/

	#include <gtest/gtest.h>

	#include <sstream>
	#include <string>

	#include "base/gtest/cur_tick_fake.hh"
	#include "base/gtest/logging.hh"
	#include "base/named.hh"
	#include "base/trace.hh"

	using namespace gem5;

	// In test SetGetLogger this logger will be assigned to be the one returned
	// by Tracer::getDebugLogger(). All tests before that test should assume
	// that getDebugLogger() returns a cerr-based logger, and all tests after
	// that test should assume that this logger is returned
	std::stringstream ss;
	Trace::OstreamLogger main_logger(ss);

	// Instantiate the mock class to have a valid curTick of 0
	GTestTickHandler tickHandler;

	namespace gem5
	{
	namespace debug
	{
	/** Debug flag used for the tests in this file. */
	SimpleFlag TraceTestDebugFlag("TraceTestDebugFlag",
	"Exclusive debug flag for the trace tests");
	} // namespace debug
	} // namespace gem5

	/** @return The ostream as a std::string. */
	std::string
	getString(std::ostream &os)
	{
	auto buf = os.rdbuf();
	std::ostringstream oss;
	oss << buf;
	return oss.str();
	}

	/** @return The logger's ostream as a std::string. */
	std::string
	getString(Trace::Logger *logger)
	{
	return getString(logger->getOstream());
	}

	/** Test creating a simple log message. */
	TEST(TraceTest, LogSimpleMessage)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.logMessage(Tick(100), "", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Test message");
	}

	/** Test creating a simple log message with a name. */
	TEST(TraceTest, LogMessageName)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	}

	/** Test that when the tick is set to MaxTick it is not printed. */
	TEST(TraceTest, LogMessageMaxTick)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.logMessage(MaxTick, "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), "Foo: Test message");
	}

	/** Test that by default the flag is not printed. */
	TEST(TraceTest, LogMessageFlagDisabled)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.logMessage(Tick(100), "Foo", "Bar", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	}

	/**
	* Test creating a simple log message without tick information and that
	* enabling and disabling format flags work.
	*/
	TEST(TraceTest, LogMessageTickDisabledAndEnableDisable)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");

	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("FmtTicksOff", true));

	logger.logMessage(Tick(200), "Foo", "", "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(&logger), "Foo: Test message");
	#else
	ASSERT_EQ(getString(&logger), " 200: Foo: Test message");
	#endif

	debug::changeFlag("FmtTicksOff", false);
	Trace::disable();

	logger.logMessage(Tick(300), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 300: Foo: Test message");
	}

	/**
	* Test creating a full log message to verify expected order of appearance.
	* This does not include the backtrace.
	*/
	TEST(TraceTest, LogMessageFlagEnabled)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));

	logger.logMessage(Tick(100), "Foo", "Bar", "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(&logger), " 100: Bar: Foo: Test message");
	#else
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	#endif

	debug::changeFlag("FmtFlag", false);
	Trace::disable();
	}

	/** Test that log messages are not displayed for ignored objects (single). */
	TEST(TraceTest, LogMessageIgnoreOne)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	ObjectMatch ignore_foo("Foo");
	ObjectMatch ignore_bar("Bar");

	// Ignore foo
	logger.setIgnore(ignore_foo);
	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	logger.logMessage(Tick(100), "Bar", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Bar: Test message");

	// Make sure that when setting a new ignore the old ignores are not kept
	logger.setIgnore(ignore_bar);
	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	logger.logMessage(Tick(100), "Bar", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	}

	/** Test that log messages are not displayed for ignored objects (multiple). */
	TEST(TraceTest, LogMessageIgnoreMultiple)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	ObjectMatch ignore_foo("Foo");
	ObjectMatch ignore_bar("Bar");
	ObjectMatch ignore_thy("Thy");

	// Ignore foo and bar
	logger.setIgnore(ignore_foo);
	logger.addIgnore(ignore_bar);
	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	logger.logMessage(Tick(100), "Bar", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	logger.logMessage(Tick(100), "Thy", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Thy: Test message");

	// Make sure that when setting a new ignore, the old sub-ignores
	// are not kept
	logger.setIgnore(ignore_thy);
	logger.logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	logger.logMessage(Tick(100), "Bar", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Bar: Test message");
	logger.logMessage(Tick(100), "Thy", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	}

	/** Test that dumping for an ignored name does not log anything. */
	TEST(TraceTest, DumpIgnored)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	ObjectMatch ignore_foo("Foo");
	logger.setIgnore(ignore_foo);
	std::string message = "Test message";
	logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "");
	ASSERT_EQ(getString(&logger), "");
	}

	/**
	* Test that a regular dump will change the message so that it contains both
	* the hex and char representation of every byte. There is a space between
	* every 8 bytes. For each 16-byte line of a message the order of appearance is
	* <byte number> <2 spaces> <8 spaced bytes> <1 space> <8 spaced bytes>
	* <3-spaces missing to fill 16 bytes> <1 space> <16 bytes as chars> <\n>
	*/
	TEST(TraceTest, DumpSimple)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	std::string message = "Test message";
	logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "Bar");
	#if TRACING_ON
	ASSERT_EQ(getString(&logger),
	// logMessage prefix
	" 100: Bar: Foo: "
	// Byte number + 2 spaces
	"00000000 "
	// 8 bytes + 1 space + 4 bytes + ((16 - 12) * 3) spaces
	"54 65 73 74 20 6d 65 73 73 61 67 65 "
	// 1 space + 12 chars + \n
	" Test message\n");
	#else
	ASSERT_EQ(getString(&logger),
	// logMessage prefix
	" 100: Foo: "
	// Byte number + 2 spaces
	"00000000 "
	// 8 bytes + 1 space + 4 bytes + ((16 - 12) * 3) spaces
	"54 65 73 74 20 6d 65 73 73 61 67 65 "
	// 1 space + 12 chars + \n
	" Test message\n");
	#endif
	debug::changeFlag("FmtFlag", false);
	Trace::disable();
	}

	/**
	* Test that a regular dump will change the message so that it contains both
	* the hex and char representation of every byte, for a multi-line message.
	*/
	TEST(TraceTest, DumpMultiLine)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	std::string message =
	"This is a very long line that will span over multiple lines";
	logger.dump(Tick(100), "Foo", message.c_str(), message.size(), "");
	ASSERT_EQ(getString(&logger),
	" 100: Foo: 00000000 "
	"54 68 69 73 20 69 73 20 61 20 76 65 72 79 20 6c This is a very l\n"
	" 100: Foo: 00000010 "
	"6f 6e 67 20 6c 69 6e 65 20 74 68 61 74 20 77 69 ong line that wi\n"
	" 100: Foo: 00000020 "
	"6c 6c 20 73 70 61 6e 20 6f 76 65 72 20 6d 75 6c ll span over mul\n"
	" 100: Foo: 00000030 "
	"74 69 70 6c 65 20 6c 69 6e 65 73 tiple lines\n");
	}

	/**
	* Test that when no logger exists a logger is created redirecting to cerr.
	* This is the only test that uses cerr. All other test will use main_logger.
	*/
	TEST(TraceTest, DISABLED_GetNullLogger)
	{
	Trace::Logger *logger = Trace::getDebugLogger();
	ASSERT_FALSE(logger == nullptr);

	gtestLogOutput.str("");
	logger->logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(gtestLogOutput.str(), " 100: Foo: Test message");
	}

	/** Test that the logger is set properly. */
	TEST(TraceTest, SetGetLogger)
	{
	// NOTE: From now on getDebugLogger will use main_logger to avoid
	// having to check cerr. This assumes that tests are run in the order
	// they appear from line 1 to the last line of this file.
	Trace::setDebugLogger(&main_logger);

	// Set message with local variable, and retrieve the string with
	// the debug-logger getter
	main_logger.logMessage(Tick(100), "Foo", "", "Test message");
	auto logger_from_getter = Trace::getDebugLogger();
	ASSERT_EQ(getString(logger_from_getter), " 100: Foo: Test message");
	}

	/** Test that output() gets the ostream of the current debug logger. */
	TEST(TraceTest, Output)
	{
	Trace::getDebugLogger()->logMessage(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(Trace::output()), " 100: Foo: Test message");
	}

	/** Test dprintf_flag with ignored name. */
	TEST(TraceTest, DprintfFlagIgnore)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	ObjectMatch ignore_foo("Foo");
	logger.setIgnore(ignore_foo);
	logger.dprintf_flag(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), "");
	}

	/** Test dprintf_flag with zero args. */
	TEST(TraceTest, DprintfFlagZeroArgs)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.dprintf_flag(Tick(100), "Foo", "", "Test message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	}

	/** Test dprintf_flag with one arg. */
	TEST(TraceTest, DprintfFlagOneArg)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.dprintf_flag(Tick(100), "Foo", "", "Test %s", "message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	}

	/** Test dprintf_flag with multiple args. */
	TEST(TraceTest, DprintfFlagMultipleArgs)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	logger.dprintf_flag(Tick(100), "Foo", "", "Test %s %c %d %x",
	"message", 'A', 217, 0x30);
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message A 217 30");
	}

	/** Test dprintf_flag with flag. */
	TEST(TraceTest, DprintfFlagEnabled)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	logger.dprintf_flag(Tick(100), "Foo", "Bar", "Test %s", "message");
	#if TRACING_ON
	ASSERT_EQ(getString(&logger), " 100: Bar: Foo: Test message");
	#else
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	#endif
	debug::changeFlag("FmtFlag", false);
	Trace::disable();
	}

	/** Test dprintf with ignored name. */
	TEST(TraceTest, DprintfIgnore)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	ObjectMatch ignore_foo("Foo");
	logger.setIgnore(ignore_foo);
	logger.dprintf(Tick(100), "Foo", "Test message");
	ASSERT_EQ(getString(&logger), "");
	}

	/** Test that dprintf does not have a flag. */
	TEST(TraceTest, DprintfEnabled)
	{
	std::stringstream ss;
	Trace::OstreamLogger logger(ss);

	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	logger.dprintf(Tick(100), "Foo", "Test %s", "message");
	ASSERT_EQ(getString(&logger), " 100: Foo: Test message");
	debug::changeFlag("FmtFlag", false);
	Trace::disable();
	}

	/** Test that dprintf is just a flagless wrapper for dprintf_flag. */
	TEST(TraceTest, DprintfWrapper)
	{
	std::stringstream ss, ss_flag;
	Trace::OstreamLogger logger(ss);
	Trace::OstreamLogger logger_flag(ss_flag);

	logger.dprintf(Tick(100), "Foo", "Test %s %c %d %x",
	"message", 'A', 217, 0x30);
	logger_flag.dprintf_flag(Tick(100), "Foo", "", "Test %s %c %d %x",
	"message", 'A', 217, 0x30);
	ASSERT_EQ(getString(&logger), getString(&logger_flag));
	}

	/** Test DDUMP with tracing on. */
	TEST(TraceTest, MacroDDUMP)
	{
	StringWrap name("Foo");
	std::string message = "Test message";

	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	DDUMP(TraceTestDebugFlag, message.c_str(), message.size());
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()),
	" 0: TraceTestDebugFlag: Foo: 00000000 "
	"54 65 73 74 20 6d 65 73 73 61 67 65 Test message\n");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	DDUMP(TraceTestDebugFlag, message.c_str(), message.size());
	ASSERT_EQ(getString(Trace::output()), "");
	}

	/** Test DPRINTF with tracing on. */
	TEST(TraceTest, MacroDPRINTF)
	{
	StringWrap name("Foo");

	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	DPRINTF(TraceTestDebugFlag, "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()),
	" 0: TraceTestDebugFlag: Foo: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	DPRINTF(TraceTestDebugFlag, "Test message");
	ASSERT_EQ(getString(Trace::output()), "");
	}

	/** Test DPRINTFS with tracing on. */
	TEST(TraceTest, MacroDPRINTFS)
	{
	Named named("Foo");
	#if TRACING_ON
	Named *named_ptr = &named;
	#endif

	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	#if TRACING_ON
	DPRINTFS(TraceTestDebugFlag, named_ptr, "Test message");
	ASSERT_EQ(getString(Trace::output()),
	" 0: TraceTestDebugFlag: Foo: Test message");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	#if TRACING_ON
	DPRINTFS(TraceTestDebugFlag, named_ptr, "Test message");
	ASSERT_EQ(getString(Trace::output()), "");
	#endif
	}

	/** Test DPRINTFR with tracing on. */
	TEST(TraceTest, MacroDPRINTFR)
	{
	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	DPRINTFR(TraceTestDebugFlag, "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()), "TraceTestDebugFlag: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	DPRINTFR(TraceTestDebugFlag, "Test message");
	ASSERT_EQ(getString(Trace::output()), "");
	}

	/** Test DPRINTFN with tracing on. */
	TEST(TraceTest, MacroDPRINTFN)
	{
	StringWrap name("Foo");
	DPRINTFN("Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()), " 0: Foo: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif
	}

	/** Test DPRINTFNR with tracing on. */
	TEST(TraceTest, MacroDPRINTFNR)
	{
	DPRINTFNR("Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()), "Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif
	}

	/** Test DPRINTF_UNCONDITIONAL with tracing on. */
	TEST(TraceTest, MacroDPRINTF_UNCONDITIONAL)
	{
	StringWrap name("Foo");

	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	DPRINTF_UNCONDITIONAL(TraceTestDebugFlag, "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()),
	" 0: TraceTestDebugFlag: Foo: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	DPRINTF_UNCONDITIONAL(TraceTestDebugFlag, "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()), " 0: Foo: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif
	}

	/**
	* Test that there is a global name() to fall through when a locally scoped
	* name() is not defined.
	*/
	TEST(TraceTest, GlobalName)
	{
	// Flag enabled
	Trace::enable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", true));
	EXPECT_TRUE(debug::changeFlag("FmtFlag", true));
	DPRINTF(TraceTestDebugFlag, "Test message");
	#if TRACING_ON
	ASSERT_EQ(getString(Trace::output()),
	" 0: TraceTestDebugFlag: global: Test message");
	#else
	ASSERT_EQ(getString(Trace::output()), "");
	#endif

	// Flag disabled
	Trace::disable();
	EXPECT_TRUE(debug::changeFlag("TraceTestDebugFlag", false));
	DPRINTF(TraceTestDebugFlag, "Test message");
	ASSERT_EQ(getString(Trace::output()), "");
	}