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 <iostream>

BUG=dawn:286

Change-Id: Ie0d018f49bcac1a7b740739a6e59d45ae6728638
Reviewed-on: https://dawn-review.googlesource.com/c/dawn/+/14102
Commit-Queue: Corentin Wallez <cwallez@chromium.org>
Reviewed-by: David Turner <digit@google.com>
Reviewed-by: Austin Eng <enga@chromium.org>

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 <algorithm>
 #include <cstring>
-#include <iostream>
 
 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 {

src/common/Assert.cpp

@@ -13,14 +13,13 @@
 // limitations under the License.
 
 #include "common/Assert.h"
-
+#include "common/Log.h"
-#include <iostream>
 
 void HandleAssertionFailure(const char* file,
                             const char* function,
                             int line,
                             const char* condition) {
-    std::cerr << "Assertion failure at " << file << ":" << line << " (" << function
+    ErrorLog() << "Assertion failure at " << file << ":" << line << " (" << function
-              << "): " << condition << std::endl;
+               << "): " << condition;
     DAWN_BREAKPOINT();
 }

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" ]
+    }
   }
 }

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 <cstdio>
+
+#if defined(DAWN_PLATFORM_ANDROID)
+#    include <android/log.h>
+#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 <iostream> 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;
+}

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 <sstream>
+
+// 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 <typename T>
+    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_

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 <iostream>
-
 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;

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 <cstring>
-#include <iostream>
 
 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;
+                WarningLog() << "OpenGL error:"
-                std::cout << "    Source: " << sourceText << std::endl;
+                             << "\n    Source: " << sourceText      //
-                std::cout << "    ID: " << id << std::endl;
+                             << "\n    ID: " << id                  //
-                std::cout << "    Severity: " << severityText << std::endl;
+                             << "\n    Severity: " << severityText  //
-                std::cout << "    Message: " << message << std::endl;
+                             << "\n    Message: " << message;
 
                 // Abort on an error when in Debug mode.
                 UNREACHABLE();

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 <iostream>
 #include <set>
 
 namespace dawn_native { namespace opengl {
@@ -64,9 +64,7 @@ namespace dawn_native { namespace opengl {
                 if (infoLogLength > 1) {
                     std::vector<char> buffer(infoLogLength);
                     gl.GetShaderInfoLog(shader, infoLogLength, nullptr, &buffer[0]);
-                    std::cout << source << std::endl;
+                    ErrorLog() << source << "\nProgram compilation failed:\n" << buffer.data();
-                    std::cout << "Program compilation failed:\n";
-                    std::cout << buffer.data() << std::endl;
                 }
             }
             return shader;
@@ -97,8 +95,7 @@ namespace dawn_native { namespace opengl {
             if (infoLogLength > 1) {
                 std::vector<char> buffer(infoLogLength);
                 gl.GetProgramInfoLog(mProgram, infoLogLength, nullptr, &buffer[0]);
-                std::cout << "Program link failed:\n";
+                ErrorLog() << "Program link failed:\n" << buffer.data();
-                std::cout << buffer.data() << std::endl;
             }
         }
 

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 <iostream>
-
 #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;

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 <algorithm>
 #include <iomanip>
-#include <iostream>
 #include <sstream>
 #include <unordered_map>
 
@@ -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"
+                         "on multi-GPU systems \n";
-                      << std::endl;
             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";
+                 "\n"
-
+              << "System adapters: \n";
-    // Preparing for outputting hex numbers
-    std::cout << std::showbase << std::hex << std::setfill('0') << std::setw(4);
-
-    std::cout << "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";
+        // Preparing for outputting hex numbers
-        std::cout << "   type: " << DeviceTypeName(adapter.GetDeviceType())
+        InfoLog() << std::showbase << std::hex << std::setfill('0') << std::setw(4)
-                  << ", backend: " << ParamName(adapter.GetBackendType()) << "\n";
+
-        std::cout << "   vendorId: 0x" << vendorId.str() << ", deviceId: 0x" << deviceId.str()
+                  << " - \"" << 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() {

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)                               \
+#define DAWN_SKIP_TEST_IF(condition)                  \
-    if (condition) {                                               \
+    if (condition) {                                  \
-        std::cout << "Test skipped: " #condition "." << std::endl; \
+        InfoLog() << "Test skipped: " #condition "."; \
-        GTEST_SKIP();                                              \
+        GTEST_SKIP();                                 \
-        return;                                                    \
+        return;                                       \
     }
 
 template <typename Params = DawnTestParam>

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"
+                << " --trace-file: The file to dump trace results.\n";
-                << std::endl;
             continue;
         }
     }

src/utils/WGPUHelpers.cpp

@@ -16,12 +16,12 @@
 
 #include "common/Assert.h"
 #include "common/Constants.h"
+#include "common/Log.h"
 
 #include <shaderc/shaderc.hpp>
 
 #include <cstring>
 #include <iomanip>
-#include <iostream>
 #include <sstream>
 
 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 {};
         }