[K/N] Logging for runtime

kotlin-native/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2Native.kt

@@ -359,6 +359,7 @@ class K2Native : CLICompiler<K2NativeCompilerArguments>() {
                         }
                     }
                 })
+                putIfNotNull(RUNTIME_LOGS, arguments.runtimeLogs)
 
                 parseBinaryOptions(arguments, configuration).forEach { optionWithValue ->
                     configuration.put(optionWithValue)

kotlin-native/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2NativeCompilerArguments.kt

@@ -348,6 +348,9 @@ class K2NativeCompilerArguments : CommonCompilerArguments() {
     )
     var binaryOptions: Array<String>? = null
 
+    @Argument(value = "-Xruntime-logs", valueDescription = "<tag1=level1,tag2=level2,...>", description = "Enable logging for runtime with tags.")
+    var runtimeLogs: String? = null
+
     override fun configureAnalysisFlags(collector: MessageCollector, languageVersion: LanguageVersion): MutableMap<AnalysisFlag<*>, Any> =
             super.configureAnalysisFlags(collector, languageVersion).also {
                 val useExperimental = it[AnalysisFlags.useExperimental] as List<*>

kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt

@@ -62,6 +62,7 @@ class KonanConfig(val project: Project, val configuration: CompilerConfiguration
     val gcAggressive: Boolean get() = configuration.get(KonanConfigKeys.GARBAGE_COLLECTOR_AGRESSIVE)!!
     val runtimeAssertsMode: RuntimeAssertsMode get() = configuration.get(BinaryOptions.runtimeAssertionsMode) ?: RuntimeAssertsMode.IGNORE
     val workerExceptionHandling: WorkerExceptionHandling get() = configuration.get(KonanConfigKeys.WORKER_EXCEPTION_HANDLING)!!
+    val runtimeLogs: String? get() = configuration.get(KonanConfigKeys.RUNTIME_LOGS)
 
     val needVerifyIr: Boolean
         get() = configuration.get(KonanConfigKeys.VERIFY_IR) == true

kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfigurationKeys.kt

@@ -165,6 +165,7 @@ class KonanConfigKeys {
         val EXTERNAL_DEPENDENCIES: CompilerConfigurationKey<String?> =
                 CompilerConfigurationKey.create("use external dependencies to enhance IR linker error messages")
         val LLVM_VARIANT: CompilerConfigurationKey<LlvmVariant?> = CompilerConfigurationKey.create("llvm variant")
+        val RUNTIME_LOGS: CompilerConfigurationKey<String> = CompilerConfigurationKey.create("enable runtime logging")
     }
 }
 

kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/llvm/IrToBitcode.kt

@@ -2590,6 +2590,10 @@ internal class CodeGeneratorVisitor(val context: Context, val lifetimes: Map<IrE
 
         setRuntimeConstGlobal("KonanNeedDebugInfo", Int32(if (context.shouldContainDebugInfo()) 1 else 0))
         setRuntimeConstGlobal("Kotlin_runtimeAssertsMode", Int32(context.config.runtimeAssertsMode.value))
+        val runtimeLogs = context.config.runtimeLogs?.let {
+            context.llvm.staticData.cStringLiteral(it)
+        } ?: NullPointer(int8Type)
+        setRuntimeConstGlobal("Kotlin_runtimeLogs", runtimeLogs)
     }
 
     // Globals set this way cannot be const, but are overridable when producing final executable.

kotlin-native/runtime/src/gc/stms/cpp/SameThreadMarkAndSweep.cpp

@@ -5,8 +5,11 @@
 
 #include "SameThreadMarkAndSweep.hpp"
 
+#include <cinttypes>
+
 #include "CompilerConstants.hpp"
 #include "GlobalData.hpp"
+#include "Logging.hpp"
 #include "MarkAndSweepUtils.hpp"
 #include "Memory.h"
 #include "RootSet.hpp"
@@ -68,6 +71,7 @@ void gc::SameThreadMarkAndSweep::ThreadData::SafePointAllocation(size_t size) no
     if (threadData_.suspensionData().suspendIfRequested()) {
         allocatedBytes_ = 0;
     } else if (allocationOverhead + size >= gc_.GetAllocationThresholdBytes()) {
+        RuntimeLogDebug({kTagGC}, "Attempt to GC at SafePointAllocation size=%zu", size);
         allocatedBytes_ = 0;
         PerformFullGC();
     }
@@ -92,16 +96,22 @@ void gc::SameThreadMarkAndSweep::ThreadData::PerformFullGC() noexcept {
     // TODO: These will actually need to be run on a separate thread.
     // TODO: Cannot use `threadData_` here, because there's no way to transform `mm::ThreadData` into `MemoryState*`.
     AssertThreadState(ThreadState::kRunnable);
+    RuntimeLogDebug({kTagGC}, "Starting to run finalizers");
+    auto timeBeforeUs = konan::getTimeMicros();
     finalizerQueue.Finalize();
+    auto timeAfterUs = konan::getTimeMicros();
+    RuntimeLogInfo({kTagGC}, "Finished running finalizers in %" PRIu64 " microseconds", timeAfterUs - timeBeforeUs);
 }
 
 void gc::SameThreadMarkAndSweep::ThreadData::OnOOM(size_t size) noexcept {
+    RuntimeLogDebug({kTagGC}, "Attempt to GC on OOM");
     PerformFullGC();
 }
 
 void gc::SameThreadMarkAndSweep::ThreadData::SafePointRegularSlowPath() noexcept {
     safePointsCounter_ = 0;
     if (konan::getTimeMicros() - timeOfLastGcUs_ >= gc_.GetCooldownThresholdUs()) {
+        RuntimeLogDebug({kTagGC}, "Attempt to GC at SafePointRegular");
         timeOfLastGcUs_ = konan::getTimeMicros();
         PerformFullGC();
     }
@@ -128,34 +138,88 @@ gc::SameThreadMarkAndSweep::SameThreadMarkAndSweep() noexcept {
 }
 
 mm::ObjectFactory<gc::SameThreadMarkAndSweep>::FinalizerQueue gc::SameThreadMarkAndSweep::PerformFullGC() noexcept {
+    RuntimeLogDebug({kTagGC}, "Attempt to suspend threads by thread %d", konan::currentThreadId());
+    auto timeStartUs = konan::getTimeMicros();
     bool didSuspend = mm::SuspendThreads();
+    auto timeSuspendUs = konan::getTimeMicros();
     if (!didSuspend) {
+        RuntimeLogDebug({kTagGC}, "Failed to suspend threads");
         // Somebody else suspended the threads, and so ran a GC.
         // TODO: This breaks if suspension is used by something apart from GC.
         return {};
     }
+    RuntimeLogDebug({kTagGC}, "Suspended all threads in %" PRIu64 " microseconds", timeSuspendUs - timeStartUs);
 
+    RuntimeLogInfo({kTagGC}, "Started GC epoch %zu. Time since last GC %" PRIu64 " microseconds", epoch_, timeStartUs - lastGCTimestampUs_);
     KStdVector<ObjHeader*> graySet;
     for (auto& thread : mm::GlobalData::Instance().threadRegistry().LockForIter()) {
         // TODO: Maybe it's more efficient to do by the suspending thread?
         thread.Publish();
-        for (auto* object : mm::ThreadRootSet(thread)) {
+        size_t stack = 0;
-            if (!isNullOrMarker(object)) {
+        size_t tls = 0;
-                graySet.push_back(object);
+        for (auto value : mm::ThreadRootSet(thread)) {
+            if (!isNullOrMarker(value.object)) {
+                graySet.push_back(value.object);
+                switch (value.source) {
+                    case mm::ThreadRootSet::Source::kStack:
+                        ++stack;
+                        break;
+                    case mm::ThreadRootSet::Source::kTLS:
+                        ++tls;
+                        break;
+                }
+            }
+        }
+        RuntimeLogDebug({kTagGC}, "Collected root set for thread stack=%zu tls=%zu", stack, tls);
+    }
+    mm::StableRefRegistry::Instance().ProcessDeletions();
+    size_t global = 0;
+    size_t stableRef = 0;
+    for (auto value : mm::GlobalRootSet()) {
+        if (!isNullOrMarker(value.object)) {
+            graySet.push_back(value.object);
+            switch (value.source) {
+                case mm::GlobalRootSet::Source::kGlobal:
+                    ++global;
+                    break;
+                case mm::GlobalRootSet::Source::kStableRef:
+                    ++stableRef;
+                    break;
             }
         }
     }
-    mm::StableRefRegistry::Instance().ProcessDeletions();
+    auto timeRootSetUs = konan::getTimeMicros();
-    for (auto* object : mm::GlobalRootSet()) {
+    RuntimeLogDebug({kTagGC}, "Collected global root set global=%zu stableRef=%zu", global, stableRef);
-        if (!isNullOrMarker(object)) {
-            graySet.push_back(object);
-        }
-    }
 
+    // Can be unsafe, because we've stopped the world.
+    auto objectsCountBefore = mm::GlobalData::Instance().objectFactory().GetSizeUnsafe();
+
+    RuntimeLogInfo({kTagGC}, "Collected root set of size %zu of which %zu are stable refs in %" PRIu64 " microseconds", graySet.size(), stableRef, timeRootSetUs - timeSuspendUs);
     gc::Mark<MarkTraits>(std::move(graySet));
+    auto timeMarkUs = konan::getTimeMicros();
+    RuntimeLogDebug({kTagGC}, "Marked in %" PRIu64 " microseconds", timeMarkUs - timeRootSetUs);
     auto finalizerQueue = gc::Sweep<SweepTraits>(mm::GlobalData::Instance().objectFactory());
+    auto timeSweepUs = konan::getTimeMicros();
+    RuntimeLogDebug({kTagGC}, "Sweeped in %" PRIu64 " microseconds", timeSweepUs - timeMarkUs);
+
+    // Can be unsafe, because we've stopped the world.
+    auto objectsCountAfter = mm::GlobalData::Instance().objectFactory().GetSizeUnsafe();
 
     mm::ResumeThreads();
+    auto timeResumeUs = konan::getTimeMicros();
+
+    RuntimeLogDebug({kTagGC}, "Resumed threads in %" PRIu64 " microseconds.", timeResumeUs - timeSweepUs);
+
+    auto finalizersCount = finalizerQueue.size();
+    auto collectedCount = objectsCountBefore - objectsCountAfter - finalizersCount;
+
+    RuntimeLogInfo(
+            {kTagGC},
+            "Finished GC epoch %zu. Collected %zu objects, to be finalized %zu objects, %zu objects remain. Total pause time %" PRIu64
+            " microseconds",
+            epoch_, collectedCount, finalizersCount, objectsCountAfter, timeResumeUs - timeStartUs);
+    ++epoch_;
+    lastGCTimestampUs_ = timeResumeUs;
 
     return finalizerQueue;
 }

kotlin-native/runtime/src/gc/stms/cpp/SameThreadMarkAndSweep.hpp

@@ -83,6 +83,9 @@ public:
 private:
     mm::ObjectFactory<SameThreadMarkAndSweep>::FinalizerQueue PerformFullGC() noexcept;
 
+    size_t epoch_ = 0;
+    uint64_t lastGCTimestampUs_ = 0;
+
     size_t threshold_ = 100000;  // Roughly 1 safepoint per 10ms (on a subset of examples on one particular machine).
     size_t allocationThresholdBytes_ = 10 * 1024 * 1024;  // 10MiB by default.
     uint64_t cooldownThresholdUs_ = 200 * 1000; // 200 milliseconds by default.

kotlin-native/runtime/src/main/cpp/Alloc.h

@@ -122,6 +122,12 @@ bool operator!=(
 template <class T>
 class KonanDeleter {
 public:
+    KonanDeleter() = default;
+
+    // This is needed for `KStdUniquePtr` covariance: if `U*` converts to `T*` then `KStdUniquePtr<U>` converts to `KStdUniquePtr<T>`.
+    template <class U, std::enable_if_t<std::is_convertible_v<U*, T*>, std::nullptr_t> = nullptr>
+    KonanDeleter(KonanDeleter<U>) {}
+
     void operator()(T* instance) noexcept { konanDestructInstance(instance); }
 };
 

kotlin-native/runtime/src/main/cpp/CompilerConstants.hpp

@@ -7,6 +7,18 @@
 #define RUNTIME_COMPILER_CONSTANTS_H
 
 #include <cstdint>
+#if __has_include(<string_view>)
+#include <string_view>
+#elif __has_include(<experimental/string_view>)
+// TODO: Remove when wasm32 is gone.
+#include <xlocale.h>
+#include <experimental/string_view>
+namespace std {
+using string_view = std::experimental::string_view;
+}
+#else
+#error "No <string_view>"
+#endif
 
 #include "Common.h"
 
@@ -15,6 +27,7 @@
 // These are defined by setRuntimeConstGlobals in IrToBitcode.kt
 extern "C" const int32_t KonanNeedDebugInfo;
 extern "C" const int32_t Kotlin_runtimeAssertsMode;
+extern "C" const char* const Kotlin_runtimeLogs;
 
 namespace kotlin {
 namespace compiler {
@@ -52,6 +65,10 @@ ALWAYS_INLINE inline RuntimeAssertsMode runtimeAssertsMode() noexcept {
 
 WorkerExceptionHandling workerExceptionHandling() noexcept;
 
+ALWAYS_INLINE inline std::string_view runtimeLogs() noexcept {
+    return Kotlin_runtimeLogs == nullptr ? std::string_view() : std::string_view(Kotlin_runtimeLogs);
+}
+
 } // namespace compiler
 } // namespace kotlin
 

kotlin-native/runtime/src/main/cpp/Logging.cpp

@@ -0,0 +1,194 @@
+/*
+ * Copyright 2010-2021 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license
+ * that can be found in the LICENSE file.
+ */
+
+#include "Logging.hpp"
+
+#include <array>
+#if __has_include(<optional>)
+#include <optional>
+#elif __has_include(<experimental/optional>)
+// TODO: Remove when wasm32 is gone.
+#include <experimental/optional>
+namespace std {
+template <typename T>
+using optional = std::experimental::optional<T>;
+inline constexpr auto nullopt = std::experimental::nullopt;
+} // namespace std
+#else
+#error "No <optional>"
+#endif
+
+#include "Format.h"
+#include "KAssert.h"
+
+using namespace kotlin;
+
+namespace {
+
+template <typename T>
+struct ParseResult {
+    std::optional<T> value;
+    std::string_view rest;
+};
+
+ParseResult<std::string_view> ParseTag(std::string_view input) noexcept {
+    auto position = input.find('=');
+    if (position == std::string_view::npos || position == 0) {
+        return {std::nullopt, input};
+    }
+    return {input.substr(0, position), input.substr(position + 1)};
+}
+
+ParseResult<std::string_view> ParseLevelString(std::string_view input) noexcept {
+    auto position = input.find(',');
+    if (position == 0) {
+        return {std::nullopt, input};
+    }
+    if (position == std::string_view::npos) {
+        return {input, std::string_view()};
+    }
+    return {input.substr(0, position), input.substr(position + 1)};
+}
+
+std::optional<logging::Level> ParseLevel(std::string_view levelString) noexcept {
+    if (levelString == "debug") return logging::Level::kDebug;
+    if (levelString == "info") return logging::Level::kInfo;
+    if (levelString == "warning") return logging::Level::kWarning;
+    if (levelString == "error") return logging::Level::kError;
+    return std::nullopt;
+}
+
+KStdOrderedMap<KStdString, logging::Level> ParseTagsFilter(std::string_view tagsFilter) noexcept {
+    if (tagsFilter.empty()) return {};
+    KStdOrderedMap<KStdString, logging::Level> result;
+    std::string_view rest = tagsFilter;
+    while (!rest.empty()) {
+        auto tag = ParseTag(rest);
+        rest = tag.rest;
+        if (tag.value == std::nullopt) {
+            konan::consoleErrorf("Failed to parse tag at: '");
+            konan::consoleErrorUtf8(rest.data(), rest.size());
+            konan::consoleErrorf("'. No logging will be performed\n");
+            return {};
+        }
+        auto levelString = ParseLevelString(rest);
+        rest = levelString.rest;
+        auto level = levelString.value ? ParseLevel(*levelString.value) : std::nullopt;
+        if (level == std::nullopt) {
+            konan::consoleErrorf("Failed to parse level at: '");
+            konan::consoleErrorUtf8(rest.data(), rest.size());
+            konan::consoleErrorf("'. No logging will be performed\n");
+            return {};
+        }
+        result.emplace(KStdString(tag.value->data(), tag.value->size()), *level);
+    }
+    return result;
+}
+
+class LogFilter : public logging::internal::LogFilter {
+public:
+    explicit LogFilter(std::string_view tagsFilter) noexcept : tagLevelMap_(ParseTagsFilter(tagsFilter)) {}
+
+    bool Empty() const noexcept override { return tagLevelMap_.empty(); }
+
+    bool Enabled(logging::Level level, std_support::span<const char* const> tags) const noexcept override {
+        for (auto tag : tags) {
+            auto it = tagLevelMap_.find(tag);
+            if (it != tagLevelMap_.end()) {
+                if (it->second <= level) {
+                    return true;
+                }
+            }
+        }
+        return false;
+    }
+
+private:
+    // TODO: Make it more efficient.
+    KStdOrderedMap<KStdString, logging::Level> tagLevelMap_;
+};
+
+class StderrLogger : public logging::internal::Logger {
+public:
+    void Log(logging::Level level, std_support::span<const char* const> tags, std::string_view message) const noexcept override {
+        konan::consoleErrorUtf8(message.data(), message.size());
+        konan::consoleErrorf("\n");
+    }
+};
+
+std_support::span<char> FormatLevel(std_support::span<char> buffer, logging::Level level) noexcept {
+    switch (level) {
+        case logging::Level::kDebug:
+            return FormatToSpan(buffer, "[DEBUG]");
+        case logging::Level::kInfo:
+            return FormatToSpan(buffer, "[INFO]");
+        case logging::Level::kWarning:
+            return FormatToSpan(buffer, "[WARN]");
+        case logging::Level::kError:
+            return FormatToSpan(buffer, "[ERROR]");
+    }
+}
+
+std_support::span<char> FormatTags(std_support::span<char> buffer, std_support::span<const char* const> tags) noexcept {
+    // `tags` cannot be empty.
+    auto firstTag = tags.front();
+    buffer = FormatToSpan(buffer, "[%s", firstTag);
+    for (auto tag : tags.subspan(1)) {
+        buffer = FormatToSpan(buffer, ",%s", tag);
+    }
+    return FormatToSpan(buffer, "]");
+}
+
+} // namespace
+
+KStdUniquePtr<logging::internal::LogFilter> logging::internal::CreateLogFilter(std::string_view tagsFilter) noexcept {
+    return ::make_unique<::LogFilter>(tagsFilter);
+}
+
+KStdUniquePtr<logging::internal::Logger> logging::internal::CreateStderrLogger() noexcept {
+    return ::make_unique<StderrLogger>();
+}
+
+std_support::span<char> logging::internal::FormatLogEntry(
+        std_support::span<char> buffer,
+        logging::Level level,
+        std_support::span<const char* const> tags,
+        const char* format,
+        std::va_list args) noexcept {
+    buffer = FormatLevel(buffer, level);
+    buffer = FormatTags(buffer, tags);
+    buffer = FormatToSpan(buffer, " ");
+    buffer = VFormatToSpan(buffer, format, args);
+    return buffer;
+}
+
+void logging::internal::Log(
+        const LogFilter& logFilter,
+        const Logger& logger,
+        Level level,
+        std_support::span<const char* const> tags,
+        const char* format,
+        std::va_list args) noexcept {
+    if (!logFilter.Enabled(level, tags)) return;
+    // TODO: This might be suboptimal.
+    std::array<char, 1024> logEntry;
+    auto rest = FormatLogEntry(logEntry, level, tags, format, args);
+    logger.Log(level, tags, std::string_view(logEntry.data(), rest.data() - logEntry.data()));
+}
+
+void logging::Log(Level level, std::initializer_list<const char*> tags, const char* format, ...) noexcept {
+    std::va_list args;
+    va_start(args, format);
+    VLog(level, tags, format, args);
+    va_end(args);
+}
+
+void logging::VLog(Level level, std::initializer_list<const char*> tags, const char* format, std::va_list args) noexcept {
+    static auto logFilter = internal::CreateLogFilter(compiler::runtimeLogs());
+    static auto logger = internal::CreateStderrLogger();
+    RuntimeAssert(tags.size() > 0, "Cannot Log without tags");
+    std_support::span<const char* const> tagsSpan(std::data(tags), std::size(tags));
+    internal::Log(*logFilter, *logger, level, tagsSpan, format, args);
+}

kotlin-native/runtime/src/main/cpp/Logging.hpp

@@ -0,0 +1,116 @@
+/*
+ * Copyright 2010-2021 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license
+ * that can be found in the LICENSE file.
+ */
+
+#ifndef RUNTIME_LOGGING_H
+#define RUNTIME_LOGGING_H
+
+#include <cstdarg>
+#include <initializer_list>
+#if __has_include(<string_view>)
+#include <string_view>
+#elif __has_include(<experimental/string_view>)
+// TODO: Remove when wasm32 is gone.
+#include <xlocale.h>
+#include <experimental/string_view>
+namespace std {
+using string_view = std::experimental::string_view;
+}
+#else
+#error "No <string_view>"
+#endif
+
+#include "CompilerConstants.hpp"
+#include "cpp_support/Span.hpp"
+#include "Types.h"
+
+namespace kotlin {
+namespace logging {
+
+enum class Level {
+    kDebug,
+    kInfo,
+    kWarning,
+    kError,
+};
+
+namespace internal {
+
+class LogFilter {
+public:
+    virtual ~LogFilter() = default;
+
+    virtual bool Empty() const noexcept = 0;
+    virtual bool Enabled(Level level, std_support::span<const char* const> tags) const noexcept = 0;
+};
+
+KStdUniquePtr<LogFilter> CreateLogFilter(std::string_view tagsFilter) noexcept;
+
+class Logger {
+public:
+    virtual ~Logger() = default;
+
+    virtual void Log(Level level, std_support::span<const char* const> tags, std::string_view message) const noexcept = 0;
+};
+
+KStdUniquePtr<Logger> CreateStderrLogger() noexcept;
+
+std_support::span<char> FormatLogEntry(
+        std_support::span<char> buffer,
+        Level level,
+        std_support::span<const char* const> tags,
+        const char* format,
+        std::va_list args) noexcept;
+
+void Log(
+        const LogFilter& logFilter,
+        const Logger& logger,
+        Level level,
+        std_support::span<const char* const> tags,
+        const char* format,
+        std::va_list args) noexcept;
+
+} // namespace internal
+
+__attribute__((format(printf, 3, 4))) void Log(Level level, std::initializer_list<const char*> tags, const char* format, ...) noexcept;
+void VLog(Level level, std::initializer_list<const char*> tags, const char* format, std::va_list args) noexcept;
+
+} // namespace logging
+
+// Well known tags.
+// These are defined outside of logging namespace for simpler usage.
+
+inline constexpr const char* kTagGC = "gc";
+inline constexpr const char* kTagMM = "mm";
+
+} // namespace kotlin
+
+#endif // RUNTIME_LOGGING_H
+
+// Using macros to simplify forwarding of varargs without breaking __attribute__((format)) and to avoid
+// evaluating args in `...` if logging is disabled.
+
+#define RuntimeLog(level, tags, format, ...) \
+    do { \
+        if (!::kotlin::compiler::runtimeLogs().empty()) { \
+            ::kotlin::logging::Log(level, tags, format, ##__VA_ARGS__); \
+        } \
+    } while (false)
+
+#define RuntimeVLog(level, tags, format, args) \
+    do { \
+        if (!::kotlin::compiler::runtimeLogs().empty()) { \
+            ::kotlin::logging::VLog(level, tags, format, args); \
+        } \
+    } while (false)
+
+#define RuntimeLogDebug(tags, format, ...) RuntimeLog(::kotlin::logging::Level::kDebug, tags, format, ##__VA_ARGS__)
+#define RuntimeLogInfo(tags, format, ...) RuntimeLog(::kotlin::logging::Level::kInfo, tags, format, ##__VA_ARGS__)
+#define RuntimeLogWarning(tags, format, ...) RuntimeLog(::kotlin::logging::Level::kWarning, tags, format, ##__VA_ARGS__)
+#define RuntimeLogError(tags, format, ...) RuntimeLog(::kotlin::logging::Level::kError, tags, format, ##__VA_ARGS__)
+
+#define RuntimeVLogDebug(tags, format, args) RuntimeVLog(::kotlin::logging::Level::kDebug, tags, format, args)
+#define RuntimeVLogInfo(tags, format, args) RuntimeVLog(::kotlin::logging::Level::kInfo, tags, format, args)
+#define RuntimeVLogWarning(tags, format, args) RuntimeVLog(::kotlin::logging::Level::kWarning, tags, format, args)
+#define RuntimeVLogError(tags, format, args) RuntimeVLog(::kotlin::logging::Level::kError, tags, format, args)

kotlin-native/runtime/src/main/cpp/LoggingTest.cpp

@@ -0,0 +1,220 @@
+/*
+ * Copyright 2010-2021 JetBrains s.r.o. Use of this source code is governed by the Apache 2.0 license
+ * that can be found in the LICENSE file.
+ */
+
+#include "Logging.hpp"
+
+#include "gmock/gmock.h"
+#include "gtest/gtest.h"
+
+using namespace kotlin;
+
+using ::testing::_;
+
+namespace {
+
+std_support::span<char> FormatLogEntry(
+        std_support::span<char> buffer, logging::Level level, std::initializer_list<const char*> tags, const char* format, ...) {
+    std_support::span<const char* const> tagsSpan(std::data(tags), std::size(tags));
+    std::va_list args;
+    va_start(args, format);
+    auto result = logging::internal::FormatLogEntry(buffer, level, tagsSpan, format, args);
+    va_end(args);
+    return result;
+}
+
+class LogFilter {
+public:
+    explicit LogFilter(std::string_view filter) : logFilter_(logging::internal::CreateLogFilter(filter)) {}
+
+    bool Empty() const { return logFilter_->Empty(); }
+
+    bool Enabled(logging::Level level, std::initializer_list<const char*> tags) const {
+        std_support::span<const char* const> tagsSpan(std::data(tags), std::size(tags));
+        return logFilter_->Enabled(level, tagsSpan);
+    }
+
+private:
+    KStdUniquePtr<logging::internal::LogFilter> logFilter_;
+};
+
+class MockLogFilter : public logging::internal::LogFilter {
+public:
+    MOCK_METHOD(bool, Empty, (), (const, noexcept, override));
+    MOCK_METHOD(bool, Enabled, (logging::Level, std_support::span<const char* const>), (const, noexcept, override));
+};
+
+class MockLogger : public logging::internal::Logger {
+public:
+    MOCK_METHOD(void, Log, (logging::Level, std_support::span<const char* const>, std::string_view), (const, noexcept, override));
+};
+
+} // namespace
+
+TEST(LoggingTest, FormatLogEntry_Debug_OneTag) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kDebug, {"t1"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][t1] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Debug_TwoTags) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kDebug, {"t1", "t2"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][t1,t2] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Info_OneTag) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kInfo, {"t1"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][t1] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Info_TwoTags) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kInfo, {"t1", "t2"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][t1,t2] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Warning_OneTag) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kWarning, {"t1"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[WARN][t1] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Warning_TwoTags) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kWarning, {"t1", "t2"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[WARN][t1,t2] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Error_OneTag) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kError, {"t1"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][t1] Log #42"));
+}
+
+TEST(LoggingTest, FormatLogEntry_Error_TwoTags) {
+    std::array<char, 1024> buffer;
+    FormatLogEntry(buffer, logging::Level::kError, {"t1", "t2"}, "Log #%d", 42);
+    EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][t1,t2] Log #42"));
+}
+
+TEST(LoggingDeathTest, StderrLogger) {
+    auto logger = logging::internal::CreateStderrLogger();
+    EXPECT_DEATH(
+            {
+                logger->Log(logging::Level::kInfo, {}, "Message for the log");
+                std::abort();
+            },
+            "Message for the log");
+}
+
+TEST(LoggingTest, LogFilter_Empty) {
+    LogFilter filter("");
+    EXPECT_TRUE(filter.Empty());
+}
+
+TEST(LoggingTest, LogFilter_EnableOne) {
+    LogFilter filter("t1=info");
+    EXPECT_FALSE(filter.Empty());
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t1"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t2"}));
+    EXPECT_FALSE(filter.Enabled(logging::Level::kInfo, {"t2"}));
+    EXPECT_FALSE(filter.Enabled(logging::Level::kWarning, {"t2"}));
+    EXPECT_FALSE(filter.Enabled(logging::Level::kError, {"t2"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t1", "t2"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t2", "t1"}));
+}
+
+TEST(LoggingTest, LogFilter_EnableTwo) {
+    LogFilter filter("t1=info,t2=warning");
+    EXPECT_FALSE(filter.Empty());
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t1"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t2"}));
+    EXPECT_FALSE(filter.Enabled(logging::Level::kInfo, {"t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t2"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t1", "t2"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t1", "t2"}));
+
+    EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {"t2", "t1"}));
+    EXPECT_TRUE(filter.Enabled(logging::Level::kError, {"t2", "t1"}));
+}
+
+TEST(LoggingTest, LogFilter_Broken) {
+    EXPECT_TRUE(LogFilter("t1").Empty());
+    EXPECT_TRUE(LogFilter("t1=").Empty());
+    EXPECT_TRUE(LogFilter("t1=oops").Empty());
+    EXPECT_TRUE(LogFilter("t1=info,t2").Empty());
+    EXPECT_TRUE(LogFilter("t1=info,t2=").Empty());
+    EXPECT_TRUE(LogFilter("t1=info,t2=oops").Empty());
+}
+
+namespace {
+
+class LoggingLogTest : public testing::Test {
+public:
+    void Log(logging::Level level, std::initializer_list<const char*> tags, const char* format, ...) {
+        std::va_list args;
+        va_start(args, format);
+        logging::internal::Log(
+                logFilter_, logger_, level, std_support::span<const char* const>(std::data(tags), std::size(tags)), format, args);
+        va_end(args);
+    }
+
+    MockLogFilter& logFilter() { return logFilter_; }
+    MockLogger& logger() { return logger_; }
+
+private:
+    testing::StrictMock<MockLogFilter> logFilter_;
+    testing::StrictMock<MockLogger> logger_;
+};
+
+MATCHER_P(TagsAre, tags, "") {
+    KStdVector<std::string_view> actualTags;
+    for (auto tag : arg) {
+        actualTags.push_back(tag);
+    }
+    return testing::ExplainMatchResult(testing::ElementsAreArray(tags), actualTags, result_listener);
+}
+
+} // namespace
+
+TEST_F(LoggingLogTest, Log_Fail) {
+    constexpr auto level = logging::Level::kInfo;
+    const std::initializer_list<const char*> tags = {"t1", "t2"};
+    EXPECT_CALL(logFilter(), Enabled(level, TagsAre(tags))).WillOnce(testing::Return(false));
+    Log(level, tags, "Message %d", 42);
+}
+
+TEST_F(LoggingLogTest, Log_Success) {
+    constexpr auto level = logging::Level::kInfo;
+    const std::initializer_list<const char*> tags = {"t1", "t2"};
+    EXPECT_CALL(logFilter(), Enabled(level, TagsAre(tags))).WillOnce(testing::Return(true));
+    EXPECT_CALL(logger(), Log(level, TagsAre(tags), "[INFO][t1,t2] Message 42"));
+    Log(level, tags, "Message %d", 42);
+}

kotlin-native/runtime/src/main/cpp/Porting.cpp

@@ -512,7 +512,7 @@ extern "C" {
     int _ZNSt3__112__next_primeEj(unsigned long n) {
         return _ZNSt3__212__next_primeEj(n);
     }
-    void __assert_fail(const char * assertion, const char * file, unsigned int line, const char * function) {
+    void __assert_fail(const char* assertion, const char* file, int line, const char* function) {
         char buf[1024];
         konan::snprintf(buf, sizeof(buf), "%s:%d in %s: runtime assert: %s\n", file, line, function, assertion);
         Konan_abort(buf);

kotlin-native/runtime/src/mm/cpp/ObjectFactory.hpp

@@ -126,6 +126,8 @@ public:
 
         ~Producer() { Publish(); }
 
+        size_t size() const noexcept { return size_; }
+
         Node& Insert(size_t dataSize) noexcept {
             AssertCorrect();
             auto node = Node::Create(allocator_, dataSize);
@@ -137,6 +139,7 @@ public:
             }
 
             last_ = nodePtr;
+            ++size_;
             RuntimeAssert(root_ != nullptr, "Must not be empty");
             AssertCorrect();
             return *nodePtr;
@@ -172,6 +175,8 @@ public:
 
             owner_.last_ = last_;
             last_ = nullptr;
+            owner_.size_ += size_;
+            size_ = 0;
 
             RuntimeAssert(root_ == nullptr, "Must be empty");
             AssertCorrect();
@@ -186,6 +191,7 @@ public:
             // Since it's only for tests, no need to worry about stack overflows.
             root_.reset();
             last_ = nullptr;
+            size_ = 0;
         }
 
     private:
@@ -204,6 +210,7 @@ public:
         Allocator allocator_;
         unique_ptr<Node> root_;
         Node* last_ = nullptr;
+        size_t size_ = 0;
     };
 
     class Iterator {
@@ -263,6 +270,8 @@ public:
             }
         }
 
+        size_t size() const noexcept { return size_; }
+
         Iterator begin() noexcept { return Iterator(root_.get()); }
         Iterator end() noexcept { return Iterator(nullptr); }
 
@@ -279,6 +288,7 @@ public:
             }
 
             last_ = nodePtr;
+            ++size_;
             AssertCorrect();
         }
 
@@ -293,12 +303,15 @@ public:
 
         unique_ptr<Node> root_;
         Node* last_ = nullptr;
+        size_t size_ = 0;
     };
 
     class Iterable : private MoveOnly {
     public:
         explicit Iterable(ObjectFactoryStorage& owner) noexcept : owner_(owner), guard_(owner_.mutex_) {}
 
+        size_t size() const noexcept { return owner_.size_; }
+
         Iterator begin() noexcept { return Iterator(nullptr, owner_.root_.get()); }
         Iterator end() noexcept { return Iterator(owner_.last_, nullptr); }
 
@@ -326,9 +339,12 @@ public:
     // Lock `ObjectFactoryStorage` for safe iteration.
     Iterable LockForIter() noexcept { return Iterable(*this); }
 
+    size_t GetSizeUnsafe() const noexcept { return size_; }
+
     void ClearForTests() {
         root_.reset();
         last_ = nullptr;
+        size_ = 0;
     }
 
 private:
@@ -344,6 +360,7 @@ private:
             if (!root_) {
                 last_ = nullptr;
             }
+            --size_;
             AssertCorrectUnsafe();
             return {std::move(node), root_.get()};
         }
@@ -353,6 +370,7 @@ private:
         if (!previousNode->next_) {
             last_ = previousNode;
         }
+        --size_;
 
         AssertCorrectUnsafe();
         return {std::move(node), previousNode->next_.get()};
@@ -370,6 +388,7 @@ private:
 
     unique_ptr<Node> root_;
     Node* last_ = nullptr;
+    size_t size_ = 0;
     SpinLock mutex_;
 };
 
@@ -602,6 +621,8 @@ public:
             FinalizerQueue& owner_;
         };
 
+        size_t size() const noexcept { return consumer_.size(); }
+
         // TODO: Consider running it in the destructor instead.
         void Finalize() noexcept {
             for (auto node : Iterable(*this)) {
@@ -640,6 +661,8 @@ public:
     // Lock ObjectFactory for safe iteration.
     Iterable LockForIter() noexcept { return Iterable(*this); }
 
+    size_t GetSizeUnsafe() const noexcept { return storage_.GetSizeUnsafe(); }
+
     void ClearForTests() { storage_.ClearForTests(); }
 
 private:

kotlin-native/runtime/src/mm/cpp/ObjectFactoryTest.cpp

@@ -93,6 +93,7 @@ TEST(ObjectFactoryStorageTest, Empty) {
     auto actual = Collect(storage);
 
     EXPECT_THAT(actual, testing::IsEmpty());
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, DoNotPublish) {
@@ -105,6 +106,8 @@ TEST(ObjectFactoryStorageTest, DoNotPublish) {
     auto actual = Collect(storage);
 
     EXPECT_THAT(actual, testing::IsEmpty());
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
+    EXPECT_THAT(producer.size(), 2);
 }
 
 TEST(ObjectFactoryStorageTest, Publish) {
@@ -123,6 +126,9 @@ TEST(ObjectFactoryStorageTest, Publish) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 2, 10, 20));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 4);
+    EXPECT_THAT(producer1.size(), 0);
+    EXPECT_THAT(producer2.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, PublishDifferentTypes) {
@@ -156,6 +162,8 @@ TEST(ObjectFactoryStorageTest, PublishDifferentTypes) {
     EXPECT_THAT(maxAlign.value, 8);
     ++it;
     EXPECT_THAT(it, actual.end());
+    EXPECT_THAT(storage.GetSizeUnsafe(), 5);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, PublishSeveralTimes) {
@@ -182,6 +190,8 @@ TEST(ObjectFactoryStorageTest, PublishSeveralTimes) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 2, 3, 4, 5));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 5);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, PublishInDestructor) {
@@ -196,6 +206,7 @@ TEST(ObjectFactoryStorageTest, PublishInDestructor) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 2));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
 }
 
 TEST(ObjectFactoryStorageTest, FindNode) {
@@ -235,6 +246,8 @@ TEST(ObjectFactoryStorageTest, EraseFirst) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(2, 3));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, EraseMiddle) {
@@ -261,6 +274,8 @@ TEST(ObjectFactoryStorageTest, EraseMiddle) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 3));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, EraseLast) {
@@ -287,6 +302,8 @@ TEST(ObjectFactoryStorageTest, EraseLast) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 2));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, EraseAll) {
@@ -309,6 +326,8 @@ TEST(ObjectFactoryStorageTest, EraseAll) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::IsEmpty());
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, EraseTheOnlyElement) {
@@ -329,6 +348,8 @@ TEST(ObjectFactoryStorageTest, EraseTheOnlyElement) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::IsEmpty());
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
+    EXPECT_THAT(producer.size(), 0);
 }
 
 TEST(ObjectFactoryStorageTest, MoveFirst) {
@@ -358,6 +379,9 @@ TEST(ObjectFactoryStorageTest, MoveFirst) {
 
     EXPECT_THAT(actual, testing::ElementsAre(2, 3));
     EXPECT_THAT(actualConsumer, testing::ElementsAre(1));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 1);
 }
 
 TEST(ObjectFactoryStorageTest, MoveMiddle) {
@@ -387,6 +411,9 @@ TEST(ObjectFactoryStorageTest, MoveMiddle) {
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 3));
     EXPECT_THAT(actualConsumer, testing::ElementsAre(2));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 1);
 }
 
 TEST(ObjectFactoryStorageTest, MoveLast) {
@@ -416,6 +443,9 @@ TEST(ObjectFactoryStorageTest, MoveLast) {
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 2));
     EXPECT_THAT(actualConsumer, testing::ElementsAre(3));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 2);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 1);
 }
 
 TEST(ObjectFactoryStorageTest, MoveAll) {
@@ -441,6 +471,9 @@ TEST(ObjectFactoryStorageTest, MoveAll) {
 
     EXPECT_THAT(actual, testing::IsEmpty());
     EXPECT_THAT(actualConsumer, testing::ElementsAre(1, 2, 3));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 3);
 }
 
 TEST(ObjectFactoryStorageTest, MoveTheOnlyElement) {
@@ -464,6 +497,9 @@ TEST(ObjectFactoryStorageTest, MoveTheOnlyElement) {
 
     EXPECT_THAT(actual, testing::IsEmpty());
     EXPECT_THAT(actualConsumer, testing::ElementsAre(1));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 0);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 1);
 }
 
 TEST(ObjectFactoryStorageTest, MoveAndErase) {
@@ -497,6 +533,9 @@ TEST(ObjectFactoryStorageTest, MoveAndErase) {
 
     EXPECT_THAT(actual, testing::ElementsAre(1, 4, 7));
     EXPECT_THAT(actualConsumer, testing::ElementsAre(3, 6, 9));
+    EXPECT_THAT(storage.GetSizeUnsafe(), 3);
+    EXPECT_THAT(producer.size(), 0);
+    EXPECT_THAT(consumer.size(), 3);
 }
 
 TEST(ObjectFactoryStorageTest, ConcurrentPublish) {
@@ -529,6 +568,7 @@ TEST(ObjectFactoryStorageTest, ConcurrentPublish) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::UnorderedElementsAreArray(expected));
+    EXPECT_THAT(storage.GetSizeUnsafe(), expected.size());
 }
 
 TEST(ObjectFactoryStorageTest, IterWhileConcurrentPublish) {
@@ -588,6 +628,7 @@ TEST(ObjectFactoryStorageTest, IterWhileConcurrentPublish) {
     auto actualAfter = Collect<int>(storage);
 
     EXPECT_THAT(actualAfter, testing::UnorderedElementsAreArray(expectedAfter));
+    EXPECT_THAT(storage.GetSizeUnsafe(), expectedAfter.size());
 }
 
 TEST(ObjectFactoryStorageTest, EraseWhileConcurrentPublish) {
@@ -647,6 +688,7 @@ TEST(ObjectFactoryStorageTest, EraseWhileConcurrentPublish) {
     auto actual = Collect<int>(storage);
 
     EXPECT_THAT(actual, testing::UnorderedElementsAreArray(expectedAfter));
+    EXPECT_THAT(storage.GetSizeUnsafe(), expectedAfter.size());
 }
 
 using mm::internal::AllocatorWithGC;

kotlin-native/runtime/src/mm/cpp/RootSet.cpp

@@ -18,12 +18,12 @@ mm::ThreadRootSet::Iterator::Iterator(begin_t, ThreadRootSet& owner) noexcept :
 
 mm::ThreadRootSet::Iterator::Iterator(end_t, ThreadRootSet& owner) noexcept : owner_(owner), phase_(Phase::kDone) {}
 
-ObjHeader*& mm::ThreadRootSet::Iterator::operator*() noexcept {
+mm::ThreadRootSet::Value mm::ThreadRootSet::Iterator::operator*() noexcept {
     switch (phase_) {
         case Phase::kStack:
-            return *stackIterator_;
+            return {*stackIterator_, Source::kStack};
         case Phase::kTLS:
-            return **tlsIterator_;
+            return {**tlsIterator_, Source::kTLS};
         case Phase::kDone:
             RuntimeFail("Cannot dereference");
     }
@@ -84,12 +84,12 @@ mm::GlobalRootSet::Iterator::Iterator(begin_t, GlobalRootSet& owner) noexcept :
 
 mm::GlobalRootSet::Iterator::Iterator(end_t, GlobalRootSet& owner) noexcept : owner_(owner), phase_(Phase::kDone) {}
 
-ObjHeader*& mm::GlobalRootSet::Iterator::operator*() noexcept {
+mm::GlobalRootSet::Value mm::GlobalRootSet::Iterator::operator*() noexcept {
     switch (phase_) {
         case Phase::kGlobals:
-            return **globalsIterator_;
+            return {**globalsIterator_, Source::kGlobal};
         case Phase::kStableRefs:
-            return *stableRefsIterator_;
+            return {*stableRefsIterator_, Source::kStableRef};
         case Phase::kDone:
             RuntimeFail("Cannot dereference");
     }

kotlin-native/runtime/src/mm/cpp/RootSet.hpp

@@ -20,6 +20,18 @@ class ThreadData;
 
 class ThreadRootSet {
 public:
+    enum class Source {
+        kStack,
+        kTLS,
+    };
+
+    struct Value {
+        ObjHeader*& object;
+        Source source;
+
+        bool operator==(const Value& rhs) const noexcept { return object == rhs.object && source == rhs.source; }
+    };
+
     class Iterator {
     public:
         struct begin_t {};
@@ -31,7 +43,7 @@ public:
         Iterator(begin_t, ThreadRootSet& owner) noexcept;
         Iterator(end_t, ThreadRootSet& owner) noexcept;
 
-        ObjHeader*& operator*() noexcept;
+        Value operator*() noexcept;
 
         Iterator& operator++() noexcept;
 
@@ -68,6 +80,18 @@ private:
 
 class GlobalRootSet {
 public:
+    enum class Source {
+        kGlobal,
+        kStableRef,
+    };
+
+    struct Value {
+        ObjHeader*& object;
+        Source source;
+
+        bool operator==(const Value& rhs) const noexcept { return object == rhs.object && source == rhs.source; }
+    };
+
     class Iterator {
     public:
         struct begin_t {};
@@ -79,7 +103,7 @@ public:
         Iterator(begin_t, GlobalRootSet& owner) noexcept;
         Iterator(end_t, GlobalRootSet& owner) noexcept;
 
-        ObjHeader*& operator*() noexcept;
+        Value operator*() noexcept;
 
         Iterator& operator++() noexcept;
 

kotlin-native/runtime/src/mm/cpp/RootSetTest.cpp

@@ -59,12 +59,18 @@ TEST(ThreadRootSetTest, Basic) {
 
     mm::ThreadRootSet iter(stack, tls);
 
-    KStdVector<ObjHeader*> actual;
+    KStdVector<mm::ThreadRootSet::Value> actual;
-    for (auto& object : iter) {
+    for (auto object : iter) {
         actual.push_back(object);
     }
 
-    EXPECT_THAT(actual, testing::ElementsAre(entry[0], entry[1], *tls.Lookup(&key, 0), *tls.Lookup(&key, 1), *tls.Lookup(&key, 2)));
+    auto asStack = [](ObjHeader*& object) -> mm::ThreadRootSet::Value { return {object, mm::ThreadRootSet::Source::kStack}; };
+    auto asTLS = [](ObjHeader*& object) -> mm::ThreadRootSet::Value { return {object, mm::ThreadRootSet::Source::kTLS}; };
+    EXPECT_THAT(
+            actual,
+            testing::ElementsAre(
+                    asStack(entry[0]), asStack(entry[1]), asTLS(*tls.Lookup(&key, 0)), asTLS(*tls.Lookup(&key, 1)),
+                    asTLS(*tls.Lookup(&key, 2))));
 }
 
 TEST(ThreadRootSetTest, Empty) {
@@ -73,8 +79,8 @@ TEST(ThreadRootSetTest, Empty) {
 
     mm::ThreadRootSet iter(stack, tls);
 
-    KStdVector<ObjHeader*> actual;
+    KStdVector<mm::ThreadRootSet::Value> actual;
-    for (auto& object : iter) {
+    for (auto object : iter) {
         actual.push_back(object);
     }
 
@@ -103,12 +109,17 @@ TEST(GlobalRootSetTest, Basic) {
 
     mm::GlobalRootSet iter(globals, stableRefs);
 
-    KStdVector<ObjHeader*> actual;
+    KStdVector<mm::GlobalRootSet::Value> actual;
-    for (auto& object : iter) {
+    for (auto object : iter) {
         actual.push_back(object);
     }
 
-    EXPECT_THAT(actual, testing::ElementsAre(global1, global2, stableRef1, stableRef2, stableRef3));
+    auto asGlobal = [](ObjHeader*& object) -> mm::GlobalRootSet::Value { return {object, mm::GlobalRootSet::Source::kGlobal}; };
+    auto asStableRef = [](ObjHeader*& object) -> mm::GlobalRootSet::Value { return {object, mm::GlobalRootSet::Source::kStableRef}; };
+    EXPECT_THAT(
+            actual,
+            testing::ElementsAre(
+                    asGlobal(global1), asGlobal(global2), asStableRef(stableRef1), asStableRef(stableRef2), asStableRef(stableRef3)));
 }
 
 TEST(GlobalRootSetTest, Empty) {
@@ -117,8 +128,8 @@ TEST(GlobalRootSetTest, Empty) {
 
     mm::GlobalRootSet iter(globals, stableRefs);
 
-    KStdVector<ObjHeader*> actual;
+    KStdVector<mm::GlobalRootSet::Value> actual;
-    for (auto& object : iter) {
+    for (auto object : iter) {
         actual.push_back(object);
     }
 

kotlin-native/runtime/src/mm/cpp/ThreadData.hpp

@@ -7,7 +7,6 @@
 #define RUNTIME_MM_THREAD_DATA_H
 
 #include <atomic>
-#include <pthread.h>
 
 #include "GlobalData.hpp"
 #include "GlobalsRegistry.hpp"
@@ -29,7 +28,7 @@ namespace mm {
 // Pin it in memory to prevent accidental copying.
 class ThreadData final : private Pinned {
 public:
-    ThreadData(pthread_t threadId) noexcept :
+    explicit ThreadData(int threadId) noexcept :
         threadId_(threadId),
         globalsThreadQueue_(GlobalsRegistry::Instance()),
         stableRefThreadQueue_(StableRefRegistry::Instance()),
@@ -39,7 +38,7 @@ public:
 
     ~ThreadData() = default;
 
-    pthread_t threadId() const noexcept { return threadId_; }
+    int threadId() const noexcept { return threadId_; }
 
     GlobalsRegistry::ThreadQueue& globalsThreadQueue() noexcept { return globalsThreadQueue_; }
 
@@ -75,7 +74,7 @@ public:
     }
 
 private:
-    const pthread_t threadId_;
+    const int threadId_;
     GlobalsRegistry::ThreadQueue globalsThreadQueue_;
     ThreadLocalStorage tls_;
     StableRefRegistry::ThreadQueue stableRefThreadQueue_;

kotlin-native/runtime/src/mm/cpp/ThreadRegistry.cpp

@@ -6,6 +6,7 @@
 #include "ThreadRegistry.hpp"
 
 #include "GlobalData.hpp"
+#include "Porting.h"
 #include "ThreadData.hpp"
 #include "ThreadState.hpp"
 
@@ -17,7 +18,7 @@ mm::ThreadRegistry& mm::ThreadRegistry::Instance() noexcept {
 }
 
 mm::ThreadRegistry::Node* mm::ThreadRegistry::RegisterCurrentThread() noexcept {
-    auto* threadDataNode = list_.Emplace(pthread_self());
+    auto* threadDataNode = list_.Emplace(konan::currentThreadId());
     AssertThreadState(threadDataNode->Get(), ThreadState::kNative);
     Node*& currentDataNode = currentThreadDataNode_;
     RuntimeAssert(!IsCurrentThreadRegistered(), "This thread already had some data assigned to it.");

kotlin-native/runtime/src/mm/cpp/ThreadRegistryTest.cpp

@@ -24,7 +24,7 @@ TEST(ThreadRegistryTest, RegisterCurrentThread) {
         } registration;
 
         auto* threadData = registration.node->Get();
-        EXPECT_EQ(pthread_self(), threadData->threadId());
+        EXPECT_EQ(konan::currentThreadId(), threadData->threadId());
         EXPECT_EQ(threadData, mm::ThreadRegistry::Instance().CurrentThreadData());
     });
     t.join();

kotlin-native/runtime/src/mm/cpp/ThreadStateTest.cpp

@@ -185,7 +185,7 @@ TEST(ThreadStateDeathTest, IncorrectStateSwitchWithDifferentFunctions) {
 }
 
 TEST(ThreadStateDeathTest, StateSwitchCorrectness) {
-    mm::ThreadData threadData(pthread_self());
+    mm::ThreadData threadData(0);
 
     // Allowed state switches: runnable <-> native
     threadData.setState(ThreadState::kRunnable);
@@ -233,4 +233,4 @@ TEST(ThreadStateDeathTest, MovingReentrantGuard) {
                     testing::ExitedWithCode(0),
                     testing::Not(testing::ContainsRegex("runtime assert: Illegal thread state switch.")));
     });
-}
+}

kotlin-native/runtime/src/mm/cpp/ThreadSuspension.cpp

@@ -10,6 +10,8 @@
 #include <thread>
 #include <mutex>
 
+#include "Logging.hpp"
+
 namespace {
 
 bool isSuspendedOrNative(kotlin::mm::ThreadData& thread) noexcept {
@@ -54,8 +56,11 @@ NO_EXTERNAL_CALLS_CHECK bool kotlin::mm::ThreadSuspensionData::suspendIfRequeste
 NO_EXTERNAL_CALLS_CHECK bool kotlin::mm::ThreadSuspensionData::suspendIfRequestedSlowPath() noexcept {
     std::unique_lock lock(gSuspensionMutex);
     if (IsThreadSuspensionRequested()) {
+        auto threadId = konan::currentThreadId();
+        RuntimeLogDebug({kTagGC, kTagMM}, "Suspending thread %d", threadId);
         AutoReset scopedAssign(&suspended_, true);
         gSuspendsionCondVar.wait(lock, []() { return !IsThreadSuspensionRequested(); });
+        RuntimeLogDebug({kTagGC, kTagMM}, "Resuming thread %d", threadId);
         return true;
     }
     return false;

kotlin-native/runtime/src/test_support/cpp/CompilerGenerated.cpp

@@ -60,6 +60,7 @@ extern "C" {
 
 extern const int32_t KonanNeedDebugInfo = 1;
 extern const int32_t Kotlin_runtimeAssertsMode = static_cast<int32_t>(kotlin::compiler::RuntimeAssertsMode::kPanic);
+extern const char* const Kotlin_runtimeLogs = nullptr;
 
 extern const TypeInfo* theAnyTypeInfo = theAnyTypeInfoHolder.typeInfo();
 extern const TypeInfo* theArrayTypeInfo = theArrayTypeInfoHolder.typeInfo();