From 2b2b8dd090bd10ffeaab2c5bc111074429da548a Mon Sep 17 00:00:00 2001 From: "Aleksei.Glushko" Date: Mon, 16 Oct 2023 20:41:10 +0200 Subject: [PATCH] [K/N] Make runtime logs enablement compile-time evaluatable --- .../kotlin/backend/konan/KonanConfig.kt | 37 ++- .../kotlin/backend/konan/RuntimeLogging.kt | 38 +++ .../kotlin/backend/konan/llvm/IrToBitcode.kt | 7 +- .../backend.native/tests/build.gradle | 25 ++ .../tests/runtime/basic/logging.kt | 6 + .../src/alloc/custom/cpp/CustomLogging.hpp | 8 +- .../src/main/cpp/CompilerConstants.hpp | 6 +- .../runtime/src/main/cpp/Logging.cpp | 150 +++--------- .../runtime/src/main/cpp/Logging.hpp | 101 ++++++-- .../runtime/src/main/cpp/LoggingTest.cpp | 224 +++++++----------- .../src/main/cpp/ParallelProcessor.hpp | 16 +- .../runtime/src/main/cpp/Runtime.cpp | 2 + .../runtime/src/main/cpp/ScopedThread.cpp | 2 +- .../runtime/src/mm/cpp/ThreadSuspension.cpp | 4 +- .../test_support/cpp/CompilerGenerated.cpp | 3 +- 15 files changed, 321 insertions(+), 308 deletions(-) create mode 100644 kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/RuntimeLogging.kt create mode 100644 kotlin-native/backend.native/tests/runtime/basic/logging.kt diff --git a/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt index 9fd3db3f418..f89127cc0b0 100644 --- a/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt +++ b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt @@ -118,7 +118,40 @@ class KonanConfig(val project: Project, val configuration: CompilerConfiguration configuration.report(CompilerMessageSeverity.STRONG_WARNING, "Legacy exception handling in workers is deprecated") } } ?: WorkerExceptionHandling.USE_HOOK - val runtimeLogs: String? get() = configuration.get(KonanConfigKeys.RUNTIME_LOGS) + + val runtimeLogsEnabled: Boolean by lazy { + configuration.get(KonanConfigKeys.RUNTIME_LOGS) != null + } + + val runtimeLogs: Map by lazy { + val default = LoggingTag.entries.associateWith { LoggingLevel.None } + + val cfgString = configuration.get(KonanConfigKeys.RUNTIME_LOGS) ?: return@lazy default + + fun error(message: String): T? { + configuration.report(CompilerMessageSeverity.STRONG_WARNING, "$message. No logging will be performed.") + return null + } + + fun parseSingleTagLevel(tagLevel: String): Pair? { + val parts = tagLevel.split("=") + val tagStr = parts[0] + val tag = tagStr.let { + LoggingTag.parse(it) ?: error("Failed to parse log tag at \"$tagStr\"") + } + val levelStr = parts.getOrNull(1) ?: error("Failed to parse log tag-level pair at \"$tagLevel\"") + val level = parts.getOrNull(1)?.let { + LoggingLevel.parse(it) ?: error("Failed to parse log level at \"$levelStr\"") + } + if (level == LoggingLevel.None) return error("Invalid log level: \"$levelStr\"") + return tag?.let { t -> level?.let { l -> Pair(t, l) } } + } + + val configured = cfgString.split(",").map { parseSingleTagLevel(it) ?: return@lazy default } + default + configured + } + + val suspendFunctionsFromAnyThreadFromObjC: Boolean by lazy { configuration.get(BinaryOptions.objcExportSuspendFunctionLaunchThreadRestriction) == ObjCExportSuspendFunctionLaunchThreadRestriction.NONE } val freezing: Freezing get() = configuration.get(BinaryOptions.freezing)?.also { if (it != Freezing.Disabled) { @@ -474,7 +507,7 @@ class KonanConfig(val project: Project, val configuration: CompilerConfiguration internal val ignoreCacheReason = when { optimizationsEnabled -> "for optimized compilation" sanitizer != null -> "with sanitizers enabled" - runtimeLogs != null -> "with runtime logs" + runtimeLogsEnabled -> "with runtime logs" else -> null } diff --git a/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/RuntimeLogging.kt b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/RuntimeLogging.kt new file mode 100644 index 00000000000..6bc714c71fd --- /dev/null +++ b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/RuntimeLogging.kt @@ -0,0 +1,38 @@ +/* + * Copyright 2010-2023 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. + */ +package org.jetbrains.kotlin.backend.konan + +// Must match `Level` in Logging.hpp +enum class LoggingLevel(val ord: Int) { + None(0), // marks disable logs, should not be used for other purposes + Error(1), + Warning(2), + Info(3), + Debug(4); + + companion object { + fun parse(str: String) = LoggingLevel.entries.firstOrNull { + it.name.equals(str, ignoreCase = true) + } + } +} + +// Must match `Tag` in Logging.hpp +enum class LoggingTag(val ord: Int) { + Logging(0), + RT(1), + GC(2), + MM(3), + TLS(4), + Pause(5), + Alloc(6), + Balancing(7); + + companion object { + fun parse(str: String) = entries.firstOrNull { + it.name.equals(str, ignoreCase = true) + } + } +} diff --git a/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/llvm/IrToBitcode.kt b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/llvm/IrToBitcode.kt index a8eb22a2838..3690d8e4d5b 100644 --- a/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/llvm/IrToBitcode.kt +++ b/kotlin-native/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/llvm/IrToBitcode.kt @@ -3039,9 +3039,10 @@ internal fun NativeGenerationState.generateRuntimeConstantsModule() : LLVMModule setRuntimeConstGlobal("Kotlin_runtimeAssertsMode", llvm.constInt32(config.runtimeAssertsMode.value)) setRuntimeConstGlobal("Kotlin_disableMmap", llvm.constInt32(if (config.disableMmap) 1 else 0)) setRuntimeConstGlobal("Kotlin_disableAllocatorOverheadEstimate", llvm.constInt32(if (config.disableAllocatorOverheadEstimate) 1 else 0)) - val runtimeLogs = config.runtimeLogs?.let { - static.cStringLiteral(it) - } ?: NullPointer(llvm.int8Type) + + val runtimeLogs = ConstArray(llvm.int32Type, LoggingTag.entries.sortedBy { it.ord }.map { + config.runtimeLogs[it]!!.ord.let { llvm.constInt32(it) } + }) setRuntimeConstGlobal("Kotlin_runtimeLogs", runtimeLogs) setRuntimeConstGlobal("Kotlin_freezingEnabled", llvm.constInt32(if (config.freezing.enableFreezeAtRuntime) 1 else 0)) setRuntimeConstGlobal("Kotlin_freezingChecksEnabled", llvm.constInt32(if (config.freezing.enableFreezeChecks) 1 else 0)) diff --git a/kotlin-native/backend.native/tests/build.gradle b/kotlin-native/backend.native/tests/build.gradle index af8daf7cf92..ec40adc8a61 100644 --- a/kotlin-native/backend.native/tests/build.gradle +++ b/kotlin-native/backend.native/tests/build.gradle @@ -831,6 +831,31 @@ standaloneTest("cleaner_in_tls_worker") { flags = ['-opt-in=kotlin.native.internal.InternalForKotlinNative'] } +standaloneTest('logging') { + outputChecker = { out -> + out.toLowerCase().contains("[logging]") && // loging reports configured log levels on info level + out.toLowerCase().contains("logging = debug") && + out.toLowerCase().contains("gc = info") && + out.toLowerCase().contains("mm = warning") && + out.toLowerCase().contains("tls = error") && + out.toLowerCase().contains("[gc]") // gc reports initialization on info level + } + source = "runtime/basic/logging.kt" + flags = ['-Xruntime-logs=gc=info,mm=warning,tls=error,logging=debug'] +} + +standaloneTest('logging_invalid') { + outputChecker = { it.isEmpty() } + source = "runtime/basic/logging.kt" + flags = ['-Xruntime-logs=invalid=unknown,logging=debug'] +} + +standaloneTest('logging_override') { + outputChecker = { it.isEmpty() } + source = "runtime/basic/logging.kt" + flags = ['-Xruntime-logs=logging=info,logging=debug,logging=none'] +} + standaloneTest("worker_bound_reference0") { source = "runtime/concurrent/worker_bound_reference0.kt" flags = ['-tr'] diff --git a/kotlin-native/backend.native/tests/runtime/basic/logging.kt b/kotlin-native/backend.native/tests/runtime/basic/logging.kt new file mode 100644 index 00000000000..4b0c5c62cba --- /dev/null +++ b/kotlin-native/backend.native/tests/runtime/basic/logging.kt @@ -0,0 +1,6 @@ +/* + * Copyright 2010-2023 JetBrains s.r.o. and Kotlin Programming Language contributors. + * Use of this source code is governed by the Apache 2.0 license that can be found in the license/LICENSE.txt file. + */ + +fun main() {} diff --git a/kotlin-native/runtime/src/alloc/custom/cpp/CustomLogging.hpp b/kotlin-native/runtime/src/alloc/custom/cpp/CustomLogging.hpp index 6df19cbff88..573024d198a 100644 --- a/kotlin-native/runtime/src/alloc/custom/cpp/CustomLogging.hpp +++ b/kotlin-native/runtime/src/alloc/custom/cpp/CustomLogging.hpp @@ -8,9 +8,9 @@ #include "Logging.hpp" -#define CustomAllocInfo(format, ...) RuntimeLogInfo({"alloc"}, format, ##__VA_ARGS__) -#define CustomAllocDebug(format, ...) RuntimeLogDebug({"alloc"}, format, ##__VA_ARGS__) -#define CustomAllocWarning(format, ...) RuntimeLogWarning({"alloc"}, format, ##__VA_ARGS__) -#define CustomAllocError(format, ...) RuntimeLogError({"alloc"}, format, ##__VA_ARGS__) +#define CustomAllocInfo(format, ...) RuntimeLogInfo({kotlin::logging::Tag::kAlloc}, format, ##__VA_ARGS__) +#define CustomAllocDebug(format, ...) RuntimeLogDebug({kotlin::logging::Tag::kAlloc}, format, ##__VA_ARGS__) +#define CustomAllocWarning(format, ...) RuntimeLogWarning({kotlin::logging::Tag::kAlloc}, format, ##__VA_ARGS__) +#define CustomAllocError(format, ...) RuntimeLogError({kotlin::logging::Tag::kAlloc}, format, ##__VA_ARGS__) #endif diff --git a/kotlin-native/runtime/src/main/cpp/CompilerConstants.hpp b/kotlin-native/runtime/src/main/cpp/CompilerConstants.hpp index 421045001d0..a4cead9608d 100644 --- a/kotlin-native/runtime/src/main/cpp/CompilerConstants.hpp +++ b/kotlin-native/runtime/src/main/cpp/CompilerConstants.hpp @@ -26,7 +26,7 @@ extern "C" const int32_t Kotlin_needDebugInfo; extern "C" const int32_t Kotlin_runtimeAssertsMode; extern "C" const int32_t Kotlin_disableMmap; extern "C" const int32_t Kotlin_disableAllocatorOverheadEstimate; -extern "C" const char* const Kotlin_runtimeLogs; +extern "C" const int32_t Kotlin_runtimeLogs[]; extern "C" const int32_t Kotlin_concurrentWeakSweep; extern "C" const int32_t Kotlin_gcMarkSingleThreaded; extern "C" const int32_t Kotlin_freezingEnabled; @@ -82,8 +82,8 @@ ALWAYS_INLINE inline bool disableAllocatorOverheadEstimate() noexcept { return Kotlin_disableAllocatorOverheadEstimate != 0; } -ALWAYS_INLINE inline std::string_view runtimeLogs() noexcept { - return Kotlin_runtimeLogs == nullptr ? std::string_view() : std::string_view(Kotlin_runtimeLogs); +ALWAYS_INLINE inline const int32_t* runtimeLogs() noexcept { + return Kotlin_runtimeLogs; } ALWAYS_INLINE inline bool freezingEnabled() noexcept { diff --git a/kotlin-native/runtime/src/main/cpp/Logging.cpp b/kotlin-native/runtime/src/main/cpp/Logging.cpp index 79ba6b72b82..7fcacbd6204 100644 --- a/kotlin-native/runtime/src/main/cpp/Logging.cpp +++ b/kotlin-native/runtime/src/main/cpp/Logging.cpp @@ -20,115 +20,23 @@ using namespace kotlin; namespace { -template -struct ParseResult { - std::optional value; - std::string_view rest; -}; - -ParseResult 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 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 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; -} - -std::map ParseTagsFilter(std::string_view tagsFilter) noexcept { - if (tagsFilter.empty()) return {}; - std::map 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(std::string(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 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. - std::map tagLevelMap_; -}; - class StderrLogger : public logging::internal::Logger { public: - void Log(logging::Level level, std_support::span tags, std::string_view message) const noexcept override { + void Log(logging::Level level, std_support::span tags, std::string_view message) const noexcept override { konan::consoleErrorUtf8(message.data(), message.size()); } }; std_support::span FormatLevel(std_support::span 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]"); - } + return FormatToSpan(buffer, "[%s]", logging::internal::name(level)); } -std_support::span FormatTags(std_support::span buffer, std_support::span tags) noexcept { +std_support::span FormatTags(std_support::span buffer, std_support::span tags) noexcept { // `tags` cannot be empty. auto firstTag = tags.front(); - buffer = FormatToSpan(buffer, "[%s", firstTag); + buffer = FormatToSpan(buffer, "[%s", logging::internal::name(firstTag)); for (auto tag : tags.subspan(1)) { - buffer = FormatToSpan(buffer, ",%s", tag); + buffer = FormatToSpan(buffer, ",%s", logging::internal::name(tag)); } return FormatToSpan(buffer, "]"); } @@ -143,20 +51,12 @@ std_support::span FormatThread(std_support::span buffer, int threadI } struct DefaultLogContext { - ::LogFilter logFilter; StderrLogger logger; - kotlin::steady_clock::time_point initialTimestamp; - - explicit DefaultLogContext(std::string_view tagsFilter) noexcept : - logFilter(tagsFilter), initialTimestamp(kotlin::steady_clock::now()) {} + kotlin::steady_clock::time_point initialTimestamp = kotlin::steady_clock::now(); }; } // namespace -std::unique_ptr logging::internal::CreateLogFilter(std::string_view tagsFilter) noexcept { - return std::make_unique<::LogFilter>(tagsFilter); -} - std::unique_ptr logging::internal::CreateStderrLogger() noexcept { return std::make_unique(); } @@ -164,7 +64,7 @@ std::unique_ptr logging::internal::CreateStderrLogger std_support::span logging::internal::FormatLogEntry( std_support::span buffer, logging::Level level, - std_support::span tags, + std_support::span tags, int threadId, kotlin::nanoseconds timestamp, const char* format, @@ -182,35 +82,55 @@ std_support::span logging::internal::FormatLogEntry( } void logging::internal::Log( - const LogFilter& logFilter, const Logger& logger, Level level, - std_support::span tags, + std_support::span tags, int threadId, kotlin::nanoseconds timestamp, const char* format, std::va_list args) noexcept { - if (!logFilter.Enabled(level, tags)) return; + RuntimeAssert(enabled(level, tags, compiler::runtimeLogs()), "Caller must ensure that the logging requested is enabled"); // TODO: This might be suboptimal. std::array logEntry; auto rest = FormatLogEntry(logEntry, level, tags, threadId, timestamp, format, args); logger.Log(level, tags, std::string_view(logEntry.data(), rest.data() - logEntry.data())); } -void logging::Log(Level level, std::initializer_list tags, const char* format, ...) noexcept { +void logging::OnRuntimeInit() noexcept { + if (internal::enabled(Level::kInfo, {Tag::kLogging})) { + std::array buf; + std_support::span span = buf; + bool printedFirstTag = false; + for (size_t tagOrd = 0; tagOrd < static_cast(Tag::kEnumSize); ++tagOrd) { + auto tag = static_cast(tagOrd); + auto maxLevel = internal::maxLevel(tag, compiler::runtimeLogs()); + if (maxLevel > Level::kNone) { + if (printedFirstTag) { + span = FormatToSpan(span, ", "); + } + printedFirstTag = true; + span = FormatToSpan(span, "%s = %s", internal::name(tag), internal::name(maxLevel)); + } + } + RuntimeAssert(printedFirstTag, "At least logging=info must be enabled and printed"); + Log(Level::kInfo, {logging::Tag::kLogging}, "Logging enabled for: %s", buf.data()); + } +} + +void logging::Log(Level level, std::initializer_list 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 tags, const char* format, std::va_list args) noexcept { +void logging::VLog(Level level, std::initializer_list tags, const char* format, std::va_list args) noexcept { CallsCheckerIgnoreGuard guard; - [[clang::no_destroy]] static DefaultLogContext ctx(compiler::runtimeLogs()); + [[clang::no_destroy]] static DefaultLogContext ctx; RuntimeAssert(tags.size() > 0, "Cannot Log without tags"); - std_support::span tagsSpan(std::data(tags), std::size(tags)); + std_support::span tagsSpan(std::data(tags), std::size(tags)); auto threadId = konan::currentThreadId(); auto timestamp = kotlin::steady_clock::now(); - internal::Log(ctx.logFilter, ctx.logger, level, tagsSpan, threadId, timestamp - ctx.initialTimestamp, format, args); + internal::Log(ctx.logger, level, tagsSpan, threadId, timestamp - ctx.initialTimestamp, format, args); } diff --git a/kotlin-native/runtime/src/main/cpp/Logging.hpp b/kotlin-native/runtime/src/main/cpp/Logging.hpp index 82a1f7773a1..ffc4475a737 100644 --- a/kotlin-native/runtime/src/main/cpp/Logging.hpp +++ b/kotlin-native/runtime/src/main/cpp/Logging.hpp @@ -18,30 +18,80 @@ namespace kotlin { namespace logging { -enum class Level { - kDebug, - kInfo, - kWarning, - kError, +// Must match LoggingLevel in RuntimeLogging.kt +enum class Level : int32_t { + kNone = 0, + kError = 1, + kWarning = 2, + kInfo = 3, + kDebug = 4, +}; + +// Must match LoggingTag in RuntimeLogging.kt +enum class Tag : int32_t { + kLogging = 0, + kRT = 1, + kGC = 2, + kMM = 3, + kTLS = 4, + kPause = 5, + kAlloc = 6, + kBalancing = 7, + + kEnumSize = 8 }; namespace internal { -class LogFilter { -public: - virtual ~LogFilter() = default; +inline const char* name(Level level) { + switch (level) { + case Level::kNone: return "NONE"; + case Level::kError: return "ERROR"; + case Level::kWarning: return "WARNING"; + case Level::kInfo: return "INFO"; + case Level::kDebug: return "DEBUG"; + } +} - virtual bool Empty() const noexcept = 0; - virtual bool Enabled(Level level, std_support::span tags) const noexcept = 0; -}; +inline const char* name(Tag tag) { + switch (tag) { + case Tag::kLogging: return "logging"; + case Tag::kRT: return "rt"; + case Tag::kGC: return "gc"; + case Tag::kMM: return "mm"; + case Tag::kTLS: return "tls"; + case Tag::kPause: return "pause"; + case Tag::kAlloc: return "alloc"; + case Tag::kBalancing: return "balancing"; -std::unique_ptr CreateLogFilter(std::string_view tagsFilter) noexcept; + case Tag::kEnumSize: break; + } + RuntimeFail("Unexpected logging tag %d", tag); +} + +ALWAYS_INLINE inline Level maxLevel(Tag tag, const int32_t logLevels[]) { + return static_cast(logLevels[static_cast(tag)]); +} + +ALWAYS_INLINE inline bool enabled(logging::Level level, std_support::span tags, const int32_t logLevels[]) { + for (auto tag: tags) { + if (level <= maxLevel(tag, logLevels)) { + return true; + } + } + return false; +} + +ALWAYS_INLINE inline bool enabled(logging::Level level, std::initializer_list tags) noexcept { + std_support::span tagsSpan(std::data(tags), std::size(tags)); + return enabled(level, tagsSpan, compiler::runtimeLogs()); +} class Logger { public: virtual ~Logger() = default; - virtual void Log(Level level, std_support::span tags, std::string_view message) const noexcept = 0; + virtual void Log(Level level, std_support::span tags, std::string_view message) const noexcept = 0; }; std::unique_ptr CreateStderrLogger() noexcept; @@ -49,17 +99,16 @@ std::unique_ptr CreateStderrLogger() noexcept; std_support::span FormatLogEntry( std_support::span buffer, Level level, - std_support::span tags, + std_support::span tags, int threadId, kotlin::nanoseconds timestamp, const char* format, std::va_list args) noexcept; void Log( - const LogFilter& logFilter, const Logger& logger, Level level, - std_support::span tags, + std_support::span tags, int threadId, kotlin::nanoseconds timestamp, const char* format, @@ -67,18 +116,20 @@ void Log( } // namespace internal -__attribute__((format(printf, 3, 4))) void Log(Level level, std::initializer_list tags, const char* format, ...) noexcept; -void VLog(Level level, std::initializer_list tags, const char* format, std::va_list args) noexcept; +void OnRuntimeInit() noexcept; + +__attribute__((format(printf, 3, 4))) +void Log(Level level, std::initializer_list tags, const char* format, ...) noexcept; +void VLog(Level level, std::initializer_list 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"; -inline constexpr const char* kTagTLS = "tls"; -inline constexpr const char* kTagPause = "pause"; +inline constexpr auto kTagGC = logging::Tag::kGC; +inline constexpr auto kTagMM = logging::Tag::kMM; +inline constexpr auto kTagTLS = logging::Tag::kTLS; +inline constexpr auto kTagBalancing = logging::Tag::kBalancing; } // namespace kotlin @@ -89,14 +140,14 @@ inline constexpr const char* kTagPause = "pause"; #define RuntimeLog(level, tags, format, ...) \ do { \ - if (!::kotlin::compiler::runtimeLogs().empty()) { \ + if (::kotlin::logging::internal::enabled(level, tags)) { \ ::kotlin::logging::Log(level, tags, format, ##__VA_ARGS__); \ } \ } while (false) #define RuntimeVLog(level, tags, format, args) \ do { \ - if (!::kotlin::compiler::runtimeLogs().empty()) { \ + if (::kotlin::logging::internal::enabled(level, tags)) { \ ::kotlin::logging::VLog(level, tags, format, args); \ } \ } while (false) diff --git a/kotlin-native/runtime/src/main/cpp/LoggingTest.cpp b/kotlin-native/runtime/src/main/cpp/LoggingTest.cpp index 6d35fe21210..d2b712bd4fb 100644 --- a/kotlin-native/runtime/src/main/cpp/LoggingTest.cpp +++ b/kotlin-native/runtime/src/main/cpp/LoggingTest.cpp @@ -19,12 +19,12 @@ namespace { std_support::span FormatLogEntry( std_support::span buffer, logging::Level level, - std::initializer_list tags, + std::initializer_list tags, int threadId, kotlin::nanoseconds timestamp, const char* format, ...) { - std_support::span tagsSpan(std::data(tags), std::size(tags)); + std_support::span tagsSpan(std::data(tags), std::size(tags)); std::va_list args; va_start(args, format); auto result = logging::internal::FormatLogEntry(buffer, level, tagsSpan, threadId, timestamp, format, args); @@ -32,87 +32,61 @@ std_support::span FormatLogEntry( 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 tags) const { - std_support::span tagsSpan(std::data(tags), std::size(tags)); - return logFilter_->Enabled(level, tagsSpan); - } - -private: - std::unique_ptr 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, noexcept, override)); -}; - -class MockLogger : public logging::internal::Logger { -public: - MOCK_METHOD(void, Log, (logging::Level, std_support::span, std::string_view), (const, noexcept, override)); -}; - } // namespace TEST(LoggingTest, FormatLogEntry_Debug_OneTag) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kDebug, {"t1"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][t1][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kDebug, {logging::Tag::kRT}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][rt][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Debug_TwoTags) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kDebug, {"t1", "t2"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][t1,t2][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kDebug, {logging::Tag::kRT, logging::Tag::kGC}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[DEBUG][rt,gc][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Info_OneTag) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kInfo, {"t1"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][t1][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kInfo, {logging::Tag::kRT}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][rt][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Info_TwoTags) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kInfo, {"t1", "t2"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][t1,t2][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kInfo, {logging::Tag::kRT, logging::Tag::kGC}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[INFO][rt,gc][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Warning_OneTag) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kWarning, {"t1"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[WARN][t1][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kWarning, {logging::Tag::kRT}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[WARNING][rt][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Warning_TwoTags) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kWarning, {"t1", "t2"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[WARN][t1,t2][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kWarning, {logging::Tag::kRT, logging::Tag::kGC}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[WARNING][rt,gc][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Error_OneTag) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kError, {"t1"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][t1][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kError, {logging::Tag::kRT}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][rt][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Error_TwoTags) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kError, {"t1", "t2"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); - EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][t1,t2][tid#123][42.500s] Log #42\n")); + FormatLogEntry(buffer, logging::Level::kError, {logging::Tag::kRT, logging::Tag::kGC}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][rt,gc][tid#123][42.500s] Log #42\n")); } TEST(LoggingTest, FormatLogEntry_Overflow) { std::array buffer; - FormatLogEntry(buffer, logging::Level::kError, {"t1", "t2"}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); + FormatLogEntry(buffer, logging::Level::kError, {logging::Tag::kRT, logging::Tag::kGC}, 123, kotlin::nanoseconds(42'500'000'000), "Log #%d", 42); // Only 18 characters are used for the log string contents, another 2 are \n and \0. - EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][t1,t2][tid\n")); + EXPECT_THAT(buffer.data(), testing::StrEq("[ERROR][rt,gc][tid\n")); } TEST(LoggingDeathTest, StderrLogger) { @@ -125,118 +99,80 @@ TEST(LoggingDeathTest, StderrLogger) { "Message for the log"); } -TEST(LoggingTest, LogFilter_Empty) { - LogFilter filter(""); - EXPECT_TRUE(filter.Empty()); +namespace { + +class LogFilter { +public: + explicit LogFilter(std::map tagToLevel) { + logLevels_.resize(static_cast(logging::Tag::kEnumSize)); + for (auto [tag, level] : tagToLevel) { + logLevels_[static_cast(tag)] = static_cast(level); + } + } + + bool Empty() const { + return std::all_of(logLevels_.begin(), logLevels_.end(), [](int32_t levelOrd){ + return static_cast(levelOrd) == logging::Level::kNone; + }); + } + + bool Enabled(logging::Level level, std::initializer_list tags) const { + std_support::span tagsSpan(std::data(tags), std::size(tags)); + return logging::internal::enabled(level, tagsSpan, logLevels_.data()); + } + +private: + std::vector logLevels_; +}; + } TEST(LoggingTest, LogFilter_EnableOne) { - LogFilter filter("t1=info"); + LogFilter filter({{logging::Tag::kRT, logging::Level::kInfo}}); 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, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kRT})); - 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, {logging::Tag::kGC})); + EXPECT_FALSE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kGC})); + EXPECT_FALSE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kGC})); + EXPECT_FALSE(filter.Enabled(logging::Level::kError, {logging::Tag::kGC})); - 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, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kRT, logging::Tag::kGC})); - 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"})); + EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kGC, logging::Tag::kRT})); } TEST(LoggingTest, LogFilter_EnableTwo) { - LogFilter filter("t1=info,t2=warning"); + LogFilter filter({{logging::Tag::kRT, logging::Level::kInfo}, {logging::Tag::kGC, logging::Level::kWarning}}); 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, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kRT})); - 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, {logging::Tag::kGC})); + EXPECT_FALSE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kGC})); - 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, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kRT, logging::Tag::kGC})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kRT, logging::Tag::kGC})); - 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 tags, - int threadId, - kotlin::nanoseconds timestamp, - const char* format, - ...) { - std::va_list args; - va_start(args, format); - logging::internal::Log( - logFilter_, logger_, level, std_support::span(std::data(tags), std::size(tags)), threadId, timestamp, - format, args); - va_end(args); - } - - MockLogFilter& logFilter() { return logFilter_; } - MockLogger& logger() { return logger_; } - -private: - testing::StrictMock logFilter_; - testing::StrictMock logger_; -}; - -MATCHER_P(TagsAre, tags, "") { - std::vector 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 tags = {"t1", "t2"}; - EXPECT_CALL(logFilter(), Enabled(level, TagsAre(tags))).WillOnce(testing::Return(false)); - Log(level, tags, 123, kotlin::nanoseconds(42'500'000'000), "Message %d", 42); -} - -TEST_F(LoggingLogTest, Log_Success) { - constexpr auto level = logging::Level::kInfo; - const std::initializer_list tags = {"t1", "t2"}; - EXPECT_CALL(logFilter(), Enabled(level, TagsAre(tags))).WillOnce(testing::Return(true)); - EXPECT_CALL(logger(), Log(level, TagsAre(tags), "[INFO][t1,t2][tid#123][42.500s] Message 42\n")); - Log(level, tags, 123, kotlin::nanoseconds(42'500'000'000), "Message %d", 42); + EXPECT_FALSE(filter.Enabled(logging::Level::kDebug, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kInfo, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kWarning, {logging::Tag::kGC, logging::Tag::kRT})); + EXPECT_TRUE(filter.Enabled(logging::Level::kError, {logging::Tag::kGC, logging::Tag::kRT})); } diff --git a/kotlin-native/runtime/src/main/cpp/ParallelProcessor.hpp b/kotlin-native/runtime/src/main/cpp/ParallelProcessor.hpp index 7d132ac2aa3..d8a12457a85 100644 --- a/kotlin-native/runtime/src/main/cpp/ParallelProcessor.hpp +++ b/kotlin-native/runtime/src/main/cpp/ParallelProcessor.hpp @@ -77,7 +77,7 @@ public: public: explicit Worker(ParallelProcessor& dispatcher) : dispatcher_(dispatcher) { dispatcher_.registeredWorkers_.fetch_add(1, std::memory_order_relaxed); - RuntimeLogDebug({ "balancing" }, "Worker registered"); + RuntimeLogDebug({ kTagBalancing }, "Worker registered"); } ALWAYS_INLINE bool localEmpty() const noexcept { @@ -96,7 +96,7 @@ public: if (batch_.full()) { bool released = dispatcher_.releaseBatch(std::move(batch_)); if (!released) { - RuntimeLogDebug({ "balancing" }, "Batches pool overflow"); + RuntimeLogDebug({ kTagBalancing }, "Batches pool overflow"); batch_.transferAllInto(overflowList_); } batch_ = Batch{}; @@ -111,7 +111,7 @@ public: if (!acquired) { if (!overflowList_.empty()) { batch_.fillFrom(overflowList_); - RuntimeLogDebug({ "balancing" }, "Acquired %zu elements from the overflow list", batch_.elementsCount()); + RuntimeLogDebug({ kTagBalancing }, "Acquired %zu elements from the overflow list", batch_.elementsCount()); } else { bool newWorkAvailable = waitForMoreWork(); if (newWorkAvailable) continue; @@ -134,7 +134,7 @@ public: std::unique_lock lock(dispatcher_.waitMutex_); auto nowWaiting = dispatcher_.waitingWorkers_.fetch_add(1, std::memory_order_relaxed) + 1; - RuntimeLogDebug({ "balancing" }, "Worker goes to sleep (now sleeping %zu of %zu)", + RuntimeLogDebug({ kTagBalancing }, "Worker goes to sleep (now sleeping %zu of %zu)", nowWaiting, dispatcher_.registeredWorkers_.load(std::memory_order_relaxed)); if (dispatcher_.allDone_) { @@ -144,7 +144,7 @@ public: if (nowWaiting == dispatcher_.registeredWorkers_.load(std::memory_order_relaxed)) { // we are the last ones awake - RuntimeLogDebug({ "balancing" }, "Worker has detected termination"); + RuntimeLogDebug({ kTagBalancing }, "Worker has detected termination"); dispatcher_.allDone_ = true; lock.unlock(); dispatcher_.waitCV_.notify_all(); @@ -157,7 +157,7 @@ public: if (dispatcher_.allDone_) { return false; } - RuntimeLogDebug({ "balancing" }, "Worker woke up"); + RuntimeLogDebug({ kTagBalancing }, "Worker woke up"); return true; } @@ -181,7 +181,7 @@ public: private: bool releaseBatch(Batch&& batch) { RuntimeAssert(!batch.empty(), "A batch to release into shared pool must be non-empty"); - RuntimeLogDebug({ "balancing" }, "Releasing batch of %zu elements", batch.elementsCount()); + RuntimeLogDebug({ kTagBalancing }, "Releasing batch of %zu elements", batch.elementsCount()); bool shared = sharedBatches_.enqueue(std::move(batch)); if (shared) { if (waitingWorkers_.load(std::memory_order_relaxed) > 0) { @@ -196,7 +196,7 @@ private: auto acquired = sharedBatches_.dequeue(); if (acquired) { dst = std::move(*acquired); - RuntimeLogDebug({ "balancing" }, "Acquired a batch of %zu elements", dst.elementsCount()); + RuntimeLogDebug({ kTagBalancing }, "Acquired a batch of %zu elements", dst.elementsCount()); return true; } return false; diff --git a/kotlin-native/runtime/src/main/cpp/Runtime.cpp b/kotlin-native/runtime/src/main/cpp/Runtime.cpp index e45b9d01159..f736f613bab 100644 --- a/kotlin-native/runtime/src/main/cpp/Runtime.cpp +++ b/kotlin-native/runtime/src/main/cpp/Runtime.cpp @@ -10,6 +10,7 @@ #include "KAssert.h" #include "MainQueueProcessor.hpp" #include "Memory.h" +#include "Logging.hpp" #include "ObjCExportInit.h" #include "Porting.h" #include "Runtime.h" @@ -139,6 +140,7 @@ RuntimeState* initRuntime() { Kotlin_ObjCExport_initialize(); #endif InitOrDeinitGlobalVariables(INIT_GLOBALS, result->memoryState); + logging::OnRuntimeInit(); } InitOrDeinitGlobalVariables(INIT_THREAD_LOCAL_GLOBALS, result->memoryState); RuntimeAssert(result->status == RuntimeStatus::kUninitialized, "Runtime must still be in the uninitialized state"); diff --git a/kotlin-native/runtime/src/main/cpp/ScopedThread.cpp b/kotlin-native/runtime/src/main/cpp/ScopedThread.cpp index 5903cf3dfa0..1f1ae77dddf 100644 --- a/kotlin-native/runtime/src/main/cpp/ScopedThread.cpp +++ b/kotlin-native/runtime/src/main/cpp/ScopedThread.cpp @@ -22,7 +22,7 @@ void internal::setCurrentThreadName(std::string_view name) noexcept { // TODO: On Linux the maximum thread name is 16 characters. Handle automatically? int result = pthread_setname_np(pthread_self(), name.data()); if (result != 0) { - RuntimeLogWarning({"rt"}, "Failed to set thread name: %s", std::strerror(result)); + RuntimeLogWarning({logging::Tag::kRT}, "Failed to set thread name: %s", std::strerror(result)); } #endif } diff --git a/kotlin-native/runtime/src/mm/cpp/ThreadSuspension.cpp b/kotlin-native/runtime/src/mm/cpp/ThreadSuspension.cpp index 71b5a1fdcb9..3e8d9bd2d9b 100644 --- a/kotlin-native/runtime/src/mm/cpp/ThreadSuspension.cpp +++ b/kotlin-native/runtime/src/mm/cpp/ThreadSuspension.cpp @@ -31,7 +31,7 @@ ALWAYS_INLINE mm::ThreadSuspensionData::MutatorPauseHandle::MutatorPauseHandle(c auto prevState = threadData_.suspensionData().setStateNoSafePoint(ThreadState::kNative); // no special reason, fill free to implement pause from native if needed RuntimeAssert(prevState == ThreadState::kRunnable, "Expected runnable state"); - RuntimeLogDebug({kTagPause}, "Suspending mutation (%s)", reason_); + RuntimeLogDebug({logging::Tag::kPause}, "Suspending mutation (%s)", reason_); } ALWAYS_INLINE mm::ThreadSuspensionData::MutatorPauseHandle::~MutatorPauseHandle() noexcept { @@ -43,7 +43,7 @@ ALWAYS_INLINE void mm::ThreadSuspensionData::MutatorPauseHandle::resume() noexce auto prevState = threadData_.suspensionData().setStateNoSafePoint(ThreadState::kRunnable); RuntimeAssert(prevState == ThreadState::kNative, "Expected native state"); auto pauseTimeMicros = konan::getTimeMicros() - pauseStartTimeMicros_; - RuntimeLogInfo({kTagPause}, "Resuming mutation after %" PRIu64 " microseconds of suspension (%s)", pauseTimeMicros, reason_); + RuntimeLogInfo({logging::Tag::kPause}, "Resuming mutation after %" PRIu64 " microseconds of suspension (%s)", pauseTimeMicros, reason_); resumed = true; } diff --git a/kotlin-native/runtime/src/test_support/cpp/CompilerGenerated.cpp b/kotlin-native/runtime/src/test_support/cpp/CompilerGenerated.cpp index b3a5ab87430..d008820b8d7 100644 --- a/kotlin-native/runtime/src/test_support/cpp/CompilerGenerated.cpp +++ b/kotlin-native/runtime/src/test_support/cpp/CompilerGenerated.cpp @@ -5,6 +5,7 @@ #include "TestSupportCompilerGenerated.hpp" +#include "Logging.hpp" #include "ObjectTestSupport.hpp" #include "Types.h" @@ -74,7 +75,7 @@ extern const int32_t Kotlin_disableMmap = 1; extern const int32_t Kotlin_disableMmap = 0; #endif extern const int32_t Kotlin_disableAllocatorOverheadEstimate = 0; -extern const char* const Kotlin_runtimeLogs = nullptr; +extern const int32_t Kotlin_runtimeLogs[static_cast(kotlin::logging::Tag::kEnumSize)] = {0}; extern const int32_t Kotlin_concurrentWeakSweep = 1; #if KONAN_WINDOWS // parallel mark tests hang on mingw due to (presumably) a bug in winpthread