From 4b37e742d3b1726ac3742a93284fddceebbe6f42 Mon Sep 17 00:00:00 2001 From: amzn-mike <80125227+amzn-mike@users.noreply.github.com> Date: Wed, 17 Nov 2021 16:40:48 -0600 Subject: [PATCH] Add interface to allow disabling global AZ Core test environment trace bus suppression (#5594) * Add interface to allow disabling global AZ Core test environment trace bus suppression Update BaseAssetManagerTest class to disable the suppression by default Update specific asset manager tests that rely on the trace bus suppression to ReEnable it Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> * Remove nodiscard Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> * Remove unique_ptr for disable token Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> * Fix move operator Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> * Switch to having individual flags for suppression of each type of output Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> * Add cvar to force stacktrace output. Clean up whitespace Signed-off-by: amzn-mike <80125227+amzn-mike@users.noreply.github.com> --- Code/Framework/AzCore/AzCore/Debug/Trace.cpp | 35 +++++++++++++++++-- Code/Framework/AzCore/AzCore/Debug/Trace.h | 3 ++ .../AzCore/AzCore/UnitTest/UnitTest.h | 34 ++++++++++++------ .../Tests/Asset/AssetManagerLoadingTests.cpp | 17 +-------- .../Tests/Asset/BaseAssetManagerTest.cpp | 15 ++++++++ .../AzCore/Tests/Asset/BaseAssetManagerTest.h | 2 ++ 6 files changed, 77 insertions(+), 29 deletions(-) diff --git a/Code/Framework/AzCore/AzCore/Debug/Trace.cpp b/Code/Framework/AzCore/AzCore/Debug/Trace.cpp index b9e4003500..2c2b8215c0 100644 --- a/Code/Framework/AzCore/AzCore/Debug/Trace.cpp +++ b/Code/Framework/AzCore/AzCore/Debug/Trace.cpp @@ -78,6 +78,7 @@ namespace AZ::Debug constexpr LogLevel DefaultLogLevel = LogLevel::Info; AZ_CVAR_SCOPED(int, bg_traceLogLevel, DefaultLogLevel, nullptr, ConsoleFunctorFlags::Null, "Enable trace message logging in release mode. 0=disabled, 1=errors, 2=warnings, 3=info."); + AZ_CVAR_SCOPED(bool, bg_alwaysShowCallstack, false, nullptr, ConsoleFunctorFlags::Null, "Force stack trace output without allowing ebus interception."); /** * If any listener returns true, store the result so we don't outputs detailed information. @@ -279,6 +280,13 @@ namespace AZ::Debug TraceMessageResult result; EBUS_EVENT_RESULT(result, TraceMessageBus, OnPreAssert, fileName, line, funcName, message); + + if (bg_alwaysShowCallstack) + { + // If we're always showing the callstack, print it now before there's any chance of an ebus handler interrupting + PrintCallstack(g_dbgSystemWnd, 1); + } + if (result.m_value) { g_alreadyHandlingAssertOrFatal = false; @@ -304,7 +312,10 @@ namespace AZ::Debug } Output(g_dbgSystemWnd, "------------------------------------------------\n"); - PrintCallstack(g_dbgSystemWnd, 1); + if (!bg_alwaysShowCallstack) + { + PrintCallstack(g_dbgSystemWnd, 1); + } Output(g_dbgSystemWnd, "==================================================================\n"); char dialogBoxText[g_maxMessageLength]; @@ -529,6 +540,16 @@ namespace AZ::Debug } } + RawOutput(window, message); + } + + void Trace::RawOutput(const char* window, const char* message) + { + if (!window) + { + window = g_dbgSystemWnd; + } + // printf on Windows platforms seem to have a buffer length limit of 4096 characters // Therefore fwrite is used directly to write the window and message to stdout AZStd::string_view windowView{ window }; @@ -572,9 +593,19 @@ namespace AZ::Debug } azstrcat(lines[i], AZ_ARRAY_SIZE(lines[i]), "\n"); + // Use Output instead of AZ_Printf to be consistent with the exception output code and avoid // this accidentally being suppressed as a normal message - Output(window, lines[i]); + + if (bg_alwaysShowCallstack) + { + // Use Raw Output as this cannot be suppressed + RawOutput(window, lines[i]); + } + else + { + Output(window, lines[i]); + } } } } diff --git a/Code/Framework/AzCore/AzCore/Debug/Trace.h b/Code/Framework/AzCore/AzCore/Debug/Trace.h index 507ba48e53..fe33bf1b9c 100644 --- a/Code/Framework/AzCore/AzCore/Debug/Trace.h +++ b/Code/Framework/AzCore/AzCore/Debug/Trace.h @@ -73,6 +73,9 @@ namespace AZ static void Output(const char* window, const char* message); + /// Called by output to handle the actual output, does not interact with ebus or allow interception + static void RawOutput(const char* window, const char* message); + static void PrintCallstack(const char* window, unsigned int suppressCount = 0, void* nativeContext = 0); /// PEXCEPTION_POINTERS on Windows, always NULL on other platforms diff --git a/Code/Framework/AzCore/AzCore/UnitTest/UnitTest.h b/Code/Framework/AzCore/AzCore/UnitTest/UnitTest.h index 5244493c78..be9199b6c4 100644 --- a/Code/Framework/AzCore/AzCore/UnitTest/UnitTest.h +++ b/Code/Framework/AzCore/AzCore/UnitTest/UnitTest.h @@ -60,6 +60,7 @@ namespace UnitTest m_isAssertTest = true; m_numAssertsFailed = 0; } + int StopAssertTests() { m_isAssertTest = false; @@ -69,6 +70,11 @@ namespace UnitTest } bool m_isAssertTest; + bool m_suppressErrors = true; + bool m_suppressWarnings = true; + bool m_suppressAsserts = true; + bool m_suppressOutput = true; + bool m_suppressPrintf = true; int m_numAssertsFailed; }; @@ -114,7 +120,7 @@ namespace UnitTest // utility classes that you can derive from or contain, which suppress AZ_Asserts // and AZ_Errors to the below macros (processAssert, etc) - // If TraceBusHook or TraceBusRedirector have been started in your unit tests, + // If TraceBusHook or TraceBusRedirector have been started in your unit tests, // use AZ_TEST_START_TRACE_SUPPRESSION and AZ_TEST_STOP_TRACE_SUPPRESSION(numExpectedAsserts) macros to perform AZ_Assert and AZ_Error suppression class TraceBusRedirector : public AZ::Debug::TraceMessageBus::Handler @@ -124,16 +130,19 @@ namespace UnitTest if (UnitTest::TestRunner::Instance().m_isAssertTest) { UnitTest::TestRunner::Instance().ProcessAssert(message, file, line, false); + return true; } - else + else if (UnitTest::TestRunner::Instance().m_suppressAsserts) { GTEST_MESSAGE_AT_(file, line, message, ::testing::TestPartResult::kNonFatalFailure); + return true; } - return true; + + return false; } bool OnAssert(const char* /*message*/) override { - return true; // stop processing + return UnitTest::TestRunner::Instance().m_suppressAsserts; // stop processing } bool OnPreError(const char* /*window*/, const char* file, int line, const char* /*func*/, const char* message) override { @@ -142,6 +151,7 @@ namespace UnitTest UnitTest::TestRunner::Instance().ProcessAssert(message, file, line, false); return true; } + return false; } bool OnError(const char* /*window*/, const char* message) override @@ -149,12 +159,15 @@ namespace UnitTest if (UnitTest::TestRunner::Instance().m_isAssertTest) { UnitTest::TestRunner::Instance().ProcessAssert(message, __FILE__, __LINE__, UnitTest::AssertionExpr(false)); + return true; } - else + else if (UnitTest::TestRunner::Instance().m_suppressErrors) { GTEST_MESSAGE_(message, ::testing::TestPartResult::kNonFatalFailure); + return true; } - return true; // stop processing + + return false; } bool OnPreWarning(const char* /*window*/, const char* /*fileName*/, int /*line*/, const char* /*func*/, const char* /*message*/) override { @@ -163,21 +176,21 @@ namespace UnitTest } bool OnWarning(const char* /*window*/, const char* /*message*/) override { - return true; + return UnitTest::TestRunner::Instance().m_suppressWarnings; } bool OnOutput(const char* /*window*/, const char* /*message*/) override { - return true; + return UnitTest::TestRunner::Instance().m_suppressOutput; } bool OnPrintf(const char* window, const char* message) override { if (AZStd::string_view(window) == "Memory") // We want to print out the memory leak's stack traces { - ColoredPrintf(COLOR_RED, "[ MEMORY ] %s", message); + ColoredPrintf(COLOR_RED, "[ MEMORY ] %s", message); } - return true; + return UnitTest::TestRunner::Instance().m_suppressPrintf; } }; @@ -259,7 +272,6 @@ namespace UnitTest bool m_environmentSetup = false; bool m_createdAllocator = false; }; - } diff --git a/Code/Framework/AzCore/Tests/Asset/AssetManagerLoadingTests.cpp b/Code/Framework/AzCore/Tests/Asset/AssetManagerLoadingTests.cpp index 3f2d9491a7..397bbd50c9 100644 --- a/Code/Framework/AzCore/Tests/Asset/AssetManagerLoadingTests.cpp +++ b/Code/Framework/AzCore/Tests/Asset/AssetManagerLoadingTests.cpp @@ -608,24 +608,9 @@ namespace UnitTest AZ::Data::AssetData::AssetStatus expected_base_status = AZ::Data::AssetData::AssetStatus::Ready; EXPECT_EQ(baseStatus, expected_base_status); } - - struct DebugListener : AZ::Interface::Registrar - { - void AssetStatusUpdate(AZ::Data::AssetId id, AZ::Data::AssetData::AssetStatus status) override - { - AZ::Debug::Trace::Output( - "", AZStd::string::format("Status %s - %d\n", id.ToString().c_str(), static_cast(status)).c_str()); - } - void ReleaseAsset(AZ::Data::AssetId id) override - { - AZ::Debug::Trace::Output( - "", AZStd::string::format("Release %s\n", id.ToString().c_str()).c_str()); - } - }; - + TEST_F(AssetJobsFloodTest, RapidAcquireAndRelease) { - DebugListener listener; auto assetUuids = { MyAsset1Id, MyAsset2Id, diff --git a/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.cpp b/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.cpp index 4dbd3c0e1e..c6fa296cbc 100644 --- a/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.cpp +++ b/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.cpp @@ -67,7 +67,10 @@ namespace UnitTest { SerializeContextFixture::SetUp(); + SuppressTraceOutput(false); + AZ::JobManagerDesc jobDesc; + AZ::JobManagerThreadDesc threadDesc; for (size_t threadCount = 0; threadCount < GetNumJobManagerThreads(); threadCount++) { @@ -111,9 +114,21 @@ namespace UnitTest delete m_jobContext; delete m_jobManager; + // Reset back to default suppression settings to avoid affecting other tests + SuppressTraceOutput(true); + SerializeContextFixture::TearDown(); } + void BaseAssetManagerTest::SuppressTraceOutput(bool suppress) + { + UnitTest::TestRunner::Instance().m_suppressAsserts = suppress; + UnitTest::TestRunner::Instance().m_suppressErrors = suppress; + UnitTest::TestRunner::Instance().m_suppressWarnings = suppress; + UnitTest::TestRunner::Instance().m_suppressPrintf = suppress; + UnitTest::TestRunner::Instance().m_suppressOutput = suppress; + } + void BaseAssetManagerTest::WriteAssetToDisk(const AZStd::string& assetName, [[maybe_unused]] const AZStd::string& assetIdGuid) { AZStd::string assetFileName = GetTestFolderPath() + assetName; diff --git a/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.h b/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.h index 757edb3713..29c2c124cd 100644 --- a/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.h +++ b/Code/Framework/AzCore/Tests/Asset/BaseAssetManagerTest.h @@ -63,6 +63,8 @@ namespace UnitTest void SetUp() override; void TearDown() override; + static void SuppressTraceOutput(bool suppress); + // Helper methods to create and destroy actual assets on the disk for true end-to-end asset loading. void WriteAssetToDisk(const AZStd::string& assetName, const AZStd::string& assetIdGuid); void DeleteAssetFromDisk(const AZStd::string& assetName);