From 95586ff18479a8b8bfde50a9d45e13613b4d0732 Mon Sep 17 00:00:00 2001 From: Corentin Wallez Date: Thu, 5 Dec 2019 11:13:01 +0000 Subject: [PATCH] Add Log.h to replace all uses of iostream On Android iostream doesn't appear in logcat, the system log that's often used for printf debugging. Introduce Chromium/ANGLE like logging that looks like the following: InfoLog() << stuff << stuff; This makes sure the message is put in logcat on Android and removes static initializers from BUG=dawn:286 Change-Id: Ie0d018f49bcac1a7b740739a6e59d45ae6728638 Reviewed-on: https://dawn-review.googlesource.com/c/dawn/+/14102 Commit-Queue: Corentin Wallez Reviewed-by: David Turner Reviewed-by: Austin Eng --- examples/SampleUtils.cpp | 15 ++-- src/common/Assert.cpp | 7 +- src/common/BUILD.gn | 5 ++ src/common/Log.cpp | 112 ++++++++++++++++++++++++++ src/common/Log.h | 90 +++++++++++++++++++++ src/dawn_native/Instance.cpp | 5 +- src/dawn_native/opengl/BackendGL.cpp | 12 +-- src/dawn_native/opengl/PipelineGL.cpp | 9 +-- src/dawn_native/vulkan/BackendVk.cpp | 5 +- src/tests/DawnTest.cpp | 29 +++---- src/tests/DawnTest.h | 11 +-- src/tests/perf_tests/DawnPerfTest.cpp | 6 +- src/utils/WGPUHelpers.cpp | 6 +- 13 files changed, 256 insertions(+), 56 deletions(-) create mode 100644 src/common/Log.cpp create mode 100644 src/common/Log.h diff --git a/examples/SampleUtils.cpp b/examples/SampleUtils.cpp index 46d6c9a10c..56597f0eb5 100644 --- a/examples/SampleUtils.cpp +++ b/examples/SampleUtils.cpp @@ -15,6 +15,7 @@ #include "SampleUtils.h" #include "common/Assert.h" +#include "common/Log.h" #include "common/Platform.h" #include "utils/BackendBinding.h" #include "utils/TerribleCommandBuffer.h" @@ -28,31 +29,31 @@ #include #include -#include void PrintDeviceError(WGPUErrorType errorType, const char* message, void*) { + const char* errorTypeName = ""; switch (errorType) { case WGPUErrorType_Validation: - std::cout << "Validation "; + errorTypeName = "Validation"; break; case WGPUErrorType_OutOfMemory: - std::cout << "Out of memory "; + errorTypeName = "Out of memory"; break; case WGPUErrorType_Unknown: - std::cout << "Unknown "; + errorTypeName = "Unknown"; break; case WGPUErrorType_DeviceLost: - std::cout << "Device lost "; + errorTypeName = "Device lost"; break; default: UNREACHABLE(); return; } - std::cout << "error: " << message << std::endl; + ErrorLog() << errorTypeName << " error: " << message; } void PrintGLFWError(int code, const char* message) { - std::cout << "GLFW error: " << code << " - " << message << std::endl; + ErrorLog() << "GLFW error: " << code << " - " << message; } enum class CmdBufType { diff --git a/src/common/Assert.cpp b/src/common/Assert.cpp index fc88fd2a8e..dd829c829c 100644 --- a/src/common/Assert.cpp +++ b/src/common/Assert.cpp @@ -13,14 +13,13 @@ // limitations under the License. #include "common/Assert.h" - -#include +#include "common/Log.h" void HandleAssertionFailure(const char* file, const char* function, int line, const char* condition) { - std::cerr << "Assertion failure at " << file << ":" << line << " (" << function - << "): " << condition << std::endl; + ErrorLog() << "Assertion failure at " << file << ":" << line << " (" << function + << "): " << condition; DAWN_BREAKPOINT(); } diff --git a/src/common/BUILD.gn b/src/common/BUILD.gn index 585876d821..4c06976bbd 100644 --- a/src/common/BUILD.gn +++ b/src/common/BUILD.gn @@ -90,6 +90,8 @@ if (is_win || is_linux || is_mac || is_fuchsia || is_android) { "DynamicLib.cpp", "DynamicLib.h", "HashUtils.h", + "Log.cpp", + "Log.h", "Math.cpp", "Math.h", "Platform.h", @@ -116,5 +118,8 @@ if (is_win || is_linux || is_mac || is_fuchsia || is_android) { "../../third_party:vulkan_headers", ] } + if (is_android) { + libs = [ "log" ] + } } } diff --git a/src/common/Log.cpp b/src/common/Log.cpp new file mode 100644 index 0000000000..6b52ef6cd3 --- /dev/null +++ b/src/common/Log.cpp @@ -0,0 +1,112 @@ +// Copyright 2019 The Dawn Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#include "common/Log.h" + +#include "common/Assert.h" +#include "common/Platform.h" + +#include + +#if defined(DAWN_PLATFORM_ANDROID) +# include +#endif + +namespace { + + const char* SeverityName(LogSeverity severity) { + switch (severity) { + case LogSeverity::Debug: + return "Debug"; + case LogSeverity::Info: + return "Info"; + case LogSeverity::Warning: + return "Warning"; + case LogSeverity::Error: + return "Error"; + default: + UNREACHABLE(); + return ""; + } + } + +#if defined(DAWN_PLATFORM_ANDROID) + android_LogPriority AndroidLogPriority(LogSeverity severity) { + switch (severity) { + case LogSeverity::Debug: + return ANDROID_LOG_INFO; + case LogSeverity::Info: + return ANDROID_LOG_INFO; + case LogSeverity::Warning: + return ANDROID_LOG_WARN; + case LogSeverity::Error: + return ANDROID_LOG_ERROR; + default: + UNREACHABLE(); + return ANDROID_LOG_ERROR; + } + } +#endif // defined(DAWN_PLATFORM_ANDROID) + +} // anonymous namespace + +LogMessage::LogMessage(LogSeverity severity) : mSeverity(severity) { +} + +LogMessage::~LogMessage() { + std::string fullMessage = mStream.str(); + + // If this message has been moved, its stream is empty. + if (fullMessage.empty()) { + return; + } + + const char* severityName = SeverityName(mSeverity); + + FILE* outputStream = stdout; + if (mSeverity == LogSeverity::Warning || mSeverity == LogSeverity::Error) { + outputStream = stderr; + } + +#if defined(DAWN_PLATFORM_ANDROID) + android_LogPriority androidPriority = AndroidLogPriority(mSeverity); + __android_log_print(androidPriority, "Dawn", "%s: %s\n", severityName, fullMessage.c_str()); +#else // defined(DAWN_PLATFORM_ANDROID) + // Note: we use fprintf because includes static initializers. + fprintf(outputStream, "%s: %s\n", severityName, fullMessage.c_str()); + fflush(outputStream); +#endif // defined(DAWN_PLATFORM_ANDROID) +} + +LogMessage DebugLog() { + return {LogSeverity::Debug}; +} + +LogMessage InfoLog() { + return {LogSeverity::Info}; +} + +LogMessage WarningLog() { + return {LogSeverity::Warning}; +} + +LogMessage ErrorLog() { + return {LogSeverity::Error}; +} + +LogMessage DebugLog(const char* file, const char* function, int line) { + LogMessage message = DebugLog(); + message << file << ":" << line << "(" << function << ")"; + return message; +} diff --git a/src/common/Log.h b/src/common/Log.h new file mode 100644 index 0000000000..2d2411a8f1 --- /dev/null +++ b/src/common/Log.h @@ -0,0 +1,90 @@ +// Copyright 2019 The Dawn Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +#ifndef COMMON_LOG_H_ +#define COMMON_LOG_H_ + +// Dawn targets shouldn't use iostream or printf directly for several reasons: +// - iostream adds static initializers which we want to avoid. +// - printf and iostream don't show up in logcat on Android so printf debugging doesn't work but +// log-message debugging does. +// - log severity helps provide intent compared to a printf. +// +// Logging should in general be avoided: errors should go through the regular WebGPU error reporting +// mechanism and others form of logging should (TODO: eventually) go through the logging dependency +// injection, so for example they show up in Chromium's about:gpu page. Nonetheless there are some +// cases where logging is necessary and when this file was first introduced we needed to replace all +// uses of iostream so we could see them in Android's logcat. +// +// Regular logging is done using the [Debug|Info|Warning|Error]Log() function this way: +// +// InfoLog() << things << that << ostringstream << supports; // No need for a std::endl or "\n" +// +// It creates a LogMessage object that isn't stored anywhere and gets its destructor called +// immediately which outputs the stored ostringstream in the right place. +// +// This file also contains DAWN_DEBUG for "printf debugging" which works on Android and +// additionally outputs the file, line and function name. Use it this way: +// +// // Pepper this throughout code to get a log of the execution +// DAWN_DEBUG(); +// +// // Get more information +// DAWN_DEBUG() << texture.GetFormat(); + +#include + +// Log levels mostly used to signal intent where the log message is produced and used to route the +// message to the correct output. +enum class LogSeverity { + Debug, + Info, + Warning, + Error, +}; + +// Essentially an ostringstream that will print itself in its destructor. +class LogMessage { + public: + LogMessage(LogSeverity severity); + ~LogMessage(); + + LogMessage(LogMessage&& other) = default; + LogMessage& operator=(LogMessage&& other) = default; + + template + LogMessage& operator<<(T&& value) { + mStream << value; + return *this; + } + + private: + LogMessage(const LogMessage& other) = delete; + LogMessage& operator=(const LogMessage& other) = delete; + + LogSeverity mSeverity; + std::ostringstream mStream; +}; + +// Short-hands to create a LogMessage with the respective severity. +LogMessage DebugLog(); +LogMessage InfoLog(); +LogMessage WarningLog(); +LogMessage ErrorLog(); + +// DAWN_DEBUG is a helper macro that creates a DebugLog and outputs file/line/function information +LogMessage DebugLog(const char* file, const char* function, int line); +#define DAWN_DEBUG() DebugLog(__FILE__, __func__, __LINE__) + +#endif // COMMON_LOG_H_ diff --git a/src/dawn_native/Instance.cpp b/src/dawn_native/Instance.cpp index 3fc7ae889b..a5f8294bf0 100644 --- a/src/dawn_native/Instance.cpp +++ b/src/dawn_native/Instance.cpp @@ -15,10 +15,9 @@ #include "dawn_native/Instance.h" #include "common/Assert.h" +#include "common/Log.h" #include "dawn_native/ErrorData.h" -#include - namespace dawn_native { // Forward definitions of each backend's "Connect" function that creates new BackendConnection. @@ -168,7 +167,7 @@ namespace dawn_native { ErrorData* error = maybeError.AcquireError(); ASSERT(error != nullptr); - std::cout << error->GetMessage() << std::endl; + InfoLog() << error->GetMessage(); delete error; return true; diff --git a/src/dawn_native/opengl/BackendGL.cpp b/src/dawn_native/opengl/BackendGL.cpp index 65d086a845..64a32a82c1 100644 --- a/src/dawn_native/opengl/BackendGL.cpp +++ b/src/dawn_native/opengl/BackendGL.cpp @@ -15,12 +15,12 @@ #include "dawn_native/opengl/BackendGL.h" #include "common/Constants.h" +#include "common/Log.h" #include "dawn_native/Instance.h" #include "dawn_native/OpenGLBackend.h" #include "dawn_native/opengl/DeviceGL.h" #include -#include namespace dawn_native { namespace opengl { @@ -102,11 +102,11 @@ namespace dawn_native { namespace opengl { } if (type == GL_DEBUG_TYPE_ERROR) { - std::cout << "OpenGL error:" << std::endl; - std::cout << " Source: " << sourceText << std::endl; - std::cout << " ID: " << id << std::endl; - std::cout << " Severity: " << severityText << std::endl; - std::cout << " Message: " << message << std::endl; + WarningLog() << "OpenGL error:" + << "\n Source: " << sourceText // + << "\n ID: " << id // + << "\n Severity: " << severityText // + << "\n Message: " << message; // Abort on an error when in Debug mode. UNREACHABLE(); diff --git a/src/dawn_native/opengl/PipelineGL.cpp b/src/dawn_native/opengl/PipelineGL.cpp index d76b091fd6..68e3bce0f5 100644 --- a/src/dawn_native/opengl/PipelineGL.cpp +++ b/src/dawn_native/opengl/PipelineGL.cpp @@ -15,13 +15,13 @@ #include "dawn_native/opengl/PipelineGL.h" #include "common/BitSetIterator.h" +#include "common/Log.h" #include "dawn_native/BindGroupLayout.h" #include "dawn_native/opengl/Forward.h" #include "dawn_native/opengl/OpenGLFunctions.h" #include "dawn_native/opengl/PipelineLayoutGL.h" #include "dawn_native/opengl/ShaderModuleGL.h" -#include #include namespace dawn_native { namespace opengl { @@ -64,9 +64,7 @@ namespace dawn_native { namespace opengl { if (infoLogLength > 1) { std::vector buffer(infoLogLength); gl.GetShaderInfoLog(shader, infoLogLength, nullptr, &buffer[0]); - std::cout << source << std::endl; - std::cout << "Program compilation failed:\n"; - std::cout << buffer.data() << std::endl; + ErrorLog() << source << "\nProgram compilation failed:\n" << buffer.data(); } } return shader; @@ -97,8 +95,7 @@ namespace dawn_native { namespace opengl { if (infoLogLength > 1) { std::vector buffer(infoLogLength); gl.GetProgramInfoLog(mProgram, infoLogLength, nullptr, &buffer[0]); - std::cout << "Program link failed:\n"; - std::cout << buffer.data() << std::endl; + ErrorLog() << "Program link failed:\n" << buffer.data(); } } diff --git a/src/dawn_native/vulkan/BackendVk.cpp b/src/dawn_native/vulkan/BackendVk.cpp index 06a2c3417e..37efa40a2b 100644 --- a/src/dawn_native/vulkan/BackendVk.cpp +++ b/src/dawn_native/vulkan/BackendVk.cpp @@ -14,14 +14,13 @@ #include "dawn_native/vulkan/BackendVk.h" +#include "common/Log.h" #include "common/SystemUtils.h" #include "dawn_native/Instance.h" #include "dawn_native/VulkanBackend.h" #include "dawn_native/vulkan/AdapterVk.h" #include "dawn_native/vulkan/VulkanError.h" -#include - #if defined(DAWN_PLATFORM_LINUX) # if defined(DAWN_PLATFORM_ANDROID) const char kVulkanLibName[] = "libvulkan.so"; @@ -254,7 +253,7 @@ namespace dawn_native { namespace vulkan { const char* /*pLayerPrefix*/, const char* pMessage, void* /*pUserdata*/) { - std::cout << pMessage << std::endl; + WarningLog() << pMessage; ASSERT((flags & VK_DEBUG_REPORT_ERROR_BIT_EXT) == 0); return VK_FALSE; diff --git a/src/tests/DawnTest.cpp b/src/tests/DawnTest.cpp index 786520534c..29ffccee09 100644 --- a/src/tests/DawnTest.cpp +++ b/src/tests/DawnTest.cpp @@ -16,6 +16,7 @@ #include "common/Assert.h" #include "common/Constants.h" +#include "common/Log.h" #include "common/Math.h" #include "common/Platform.h" #include "dawn/dawn_proc.h" @@ -28,7 +29,6 @@ #include #include -#include #include #include @@ -159,7 +159,7 @@ DawnTestEnvironment::DawnTestEnvironment(int argc, char** argv) { } if (strcmp("-h", argv[i]) == 0 || strcmp("--help", argv[i]) == 0) { - std::cout << "\n\nUsage: " << argv[0] + InfoLog() << "\n\nUsage: " << argv[0] << " [GTEST_FLAGS...] [-w] [-d] [-c] [--adapter-vendor-id=x]\n" " -w, --use-wire: Run the tests through the wire (defaults to no wire)\n" " -d, --enable-backend-validation: Enable backend validation (defaults" @@ -168,8 +168,7 @@ DawnTestEnvironment::DawnTestEnvironment(int argc, char** argv) { "(defaults to no capture)\n" " --skip-validation: Skip Dawn validation\n" " --adapter-vendor-id: Select adapter by vendor id to run end2end tests" - "on multi-GPU systems \n" - << std::endl; + "on multi-GPU systems \n"; continue; } } @@ -188,7 +187,7 @@ void DawnTestEnvironment::SetUp() { mInstance.get()->DiscoverDefaultAdapters(); DiscoverOpenGLAdapter(); - std::cout << "Testing configuration\n" + InfoLog() << "Testing configuration\n" "---------------------\n" "UseWire: " << (mUseWire ? "true" : "false") @@ -205,12 +204,8 @@ void DawnTestEnvironment::SetUp() { "BeginCaptureOnStartup: " << (mBeginCaptureOnStartup ? "true" : "false") << "\n" - "\n"; - - // Preparing for outputting hex numbers - std::cout << std::showbase << std::hex << std::setfill('0') << std::setw(4); - - std::cout << "System adapters: \n"; + "\n" + << "System adapters: \n"; for (const dawn_native::Adapter& adapter : mInstance->GetAdapters()) { const dawn_native::PCIInfo& pci = adapter.GetPCIInfo(); @@ -221,14 +216,16 @@ void DawnTestEnvironment::SetUp() { deviceId << std::setfill('0') << std::uppercase << std::internal << std::hex << std::setw(4) << pci.deviceId; - std::cout << " - \"" << pci.name << "\"\n"; - std::cout << " type: " << DeviceTypeName(adapter.GetDeviceType()) - << ", backend: " << ParamName(adapter.GetBackendType()) << "\n"; - std::cout << " vendorId: 0x" << vendorId.str() << ", deviceId: 0x" << deviceId.str() + // Preparing for outputting hex numbers + InfoLog() << std::showbase << std::hex << std::setfill('0') << std::setw(4) + + << " - \"" << pci.name << "\"\n" + << " type: " << DeviceTypeName(adapter.GetDeviceType()) + << ", backend: " << ParamName(adapter.GetBackendType()) << "\n" + << " vendorId: 0x" << vendorId.str() << ", deviceId: 0x" << deviceId.str() << (mHasVendorIdFilter && mVendorIdFilter == pci.vendorId ? " [Selected]" : "") << "\n"; } - std::cout << std::endl; } void DawnTestEnvironment::TearDown() { diff --git a/src/tests/DawnTest.h b/src/tests/DawnTest.h index e693641733..e65e14816d 100644 --- a/src/tests/DawnTest.h +++ b/src/tests/DawnTest.h @@ -15,6 +15,7 @@ #ifndef TESTS_DAWNTEST_H_ #define TESTS_DAWNTEST_H_ +#include "common/Log.h" #include "dawn/dawn_proc_table.h" #include "dawn/webgpu_cpp.h" #include "dawn_native/DawnNative.h" @@ -294,11 +295,11 @@ class DawnTestBase { }; // Skip a test when the given condition is satisfied. -#define DAWN_SKIP_TEST_IF(condition) \ - if (condition) { \ - std::cout << "Test skipped: " #condition "." << std::endl; \ - GTEST_SKIP(); \ - return; \ +#define DAWN_SKIP_TEST_IF(condition) \ + if (condition) { \ + InfoLog() << "Test skipped: " #condition "."; \ + GTEST_SKIP(); \ + return; \ } template diff --git a/src/tests/perf_tests/DawnPerfTest.cpp b/src/tests/perf_tests/DawnPerfTest.cpp index 8a508df7ab..5d0aa1b719 100644 --- a/src/tests/perf_tests/DawnPerfTest.cpp +++ b/src/tests/perf_tests/DawnPerfTest.cpp @@ -15,6 +15,7 @@ #include "tests/perf_tests/DawnPerfTest.h" #include "common/Assert.h" +#include "common/Log.h" #include "dawn_platform/tracing/TraceEvent.h" #include "tests/perf_tests/DawnPerfTestPlatform.h" #include "utils/Timer.h" @@ -112,14 +113,13 @@ DawnPerfTestEnvironment::DawnPerfTestEnvironment(int argc, char** argv) } if (strcmp("-h", argv[i]) == 0 || strcmp("--help", argv[i]) == 0) { - std::cout + InfoLog() << "Additional flags:" << " [--calibration] [--override-steps=x] [--enable-tracing] [--trace-file=file]\n" << " --calibration: Only run calibration. Calibration allows the perf test" " runner script to save some time.\n" << " --override-steps: Set a fixed number of steps to run for each test\n" - << " --trace-file: The file to dump trace results.\n" - << std::endl; + << " --trace-file: The file to dump trace results.\n"; continue; } } diff --git a/src/utils/WGPUHelpers.cpp b/src/utils/WGPUHelpers.cpp index dcf8a2baad..d232949b14 100644 --- a/src/utils/WGPUHelpers.cpp +++ b/src/utils/WGPUHelpers.cpp @@ -16,12 +16,12 @@ #include "common/Assert.h" #include "common/Constants.h" +#include "common/Log.h" #include #include #include -#include #include namespace utils { @@ -67,7 +67,7 @@ namespace utils { shaderc::Compiler compiler; auto result = compiler.CompileGlslToSpv(source, strlen(source), kind, "myshader?"); if (result.GetCompilationStatus() != shaderc_compilation_status_success) { - std::cerr << result.GetErrorMessage(); + ErrorLog() << result.GetErrorMessage(); return {}; } #ifdef DUMP_SPIRV_ASSEMBLY @@ -106,7 +106,7 @@ namespace utils { shaderc::Compiler compiler; shaderc::SpvCompilationResult result = compiler.AssembleToSpv(source, strlen(source)); if (result.GetCompilationStatus() != shaderc_compilation_status_success) { - std::cerr << result.GetErrorMessage(); + ErrorLog() << result.GetErrorMessage(); return {}; }