From c15fb6833da58262bc83045596cd23e9878f73ad Mon Sep 17 00:00:00 2001 From: Alexander Gorshenev Date: Wed, 28 Dec 2016 18:14:10 +0300 Subject: [PATCH] Profiling machinery. --- .../org/jetbrains/kotlin/cli/bc/K2Native.kt | 9 ++-- .../cli/bc/K2NativeCompilerArguments.java | 3 ++ .../jetbrains/kotlin/backend/konan/Context.kt | 16 ++++--- .../kotlin/backend/konan/KonanConfig.kt | 12 +++--- .../backend/konan/KonanConfigurationKeys.kt | 2 + .../kotlin/backend/konan/KonanDriver.kt | 19 ++++---- .../kotlin/backend/konan/KonanPhases.kt | 43 +++++++++++++------ .../konan/descriptors/DeepPrintVisitor.kt | 3 +- .../kotlin/backend/konan/util/util.kt | 22 ++++++++++ cmd/konanc | 7 ++- 10 files changed, 97 insertions(+), 39 deletions(-) create mode 100644 backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/util/util.kt diff --git a/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2Native.kt b/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2Native.kt index fc159c75f6d..96dffefe77f 100644 --- a/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2Native.kt +++ b/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2Native.kt @@ -1,6 +1,7 @@ package org.jetbrains.kotlin.cli.bc import org.jetbrains.kotlin.backend.konan.* +import org.jetbrains.kotlin.backend.konan.util.profile import com.intellij.openapi.Disposable import org.jetbrains.kotlin.analyzer.AnalysisResult import org.jetbrains.kotlin.cli.common.CLICompiler @@ -30,9 +31,6 @@ class K2Native : CLICompiler() { rootDisposable: Disposable ): ExitCode { - - configuration.get(KonanConfigKeys.LIBRARY_FILES)?.forEach{ println(it) } - val environment = KotlinCoreEnvironment.createForProduction(rootDisposable, configuration, Arrays.asList("extensions/common.xml")) val project = environment.project @@ -101,6 +99,7 @@ class K2Native : CLICompiler() { put(VERBOSE_PHASES, arguments.verbosePhases.toNonNullList()) put(LIST_PHASES, arguments.listPhases) + put(TIME_PHASES, arguments.timePhases) }} } @@ -110,7 +109,9 @@ class K2Native : CLICompiler() { companion object { @JvmStatic fun main(args: Array) { - CLICompiler.doMain(K2Native(), args) + profile("Total compiler main()") { + CLICompiler.doMain(K2Native(), args) + } } } } diff --git a/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2NativeCompilerArguments.java b/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2NativeCompilerArguments.java index 6ca5193482e..ac125d346b7 100644 --- a/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2NativeCompilerArguments.java +++ b/backend.native/cli.bc/src/org/jetbrains/kotlin/cli/bc/K2NativeCompilerArguments.java @@ -62,5 +62,8 @@ public class K2NativeCompilerArguments extends CommonCompilerArguments { @Argument(value = "list", description = "List all backend phases") public boolean listPhases; + + @Argument(value = "time", description = "Report execution time for compiler phases") + public boolean timePhases; } diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/Context.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/Context.kt index 9df44cfbb84..a6531e24a51 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/Context.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/Context.kt @@ -19,11 +19,9 @@ import org.jetbrains.kotlin.backend.konan.llvm.verifyModule import org.jetbrains.kotlin.ir.util.DumpIrTreeVisitor import java.lang.System.out -internal final class Context(val config: KonanConfig, - // TODO: Need to eliminate when deserialization is fixed. - val bindingContext: BindingContext, - val moduleDescriptor: ModuleDescriptor - ) : KonanBackendContext() { +internal final class Context(val config: KonanConfig) : KonanBackendContext() { + + var moduleDescriptor: ModuleDescriptor? = null var irModule: IrModuleFragment? = null set(module: IrModuleFragment?) { @@ -53,6 +51,7 @@ internal final class Context(val config: KonanConfig, lateinit var llvm: Llvm var phase: KonanPhase? = null + var depth: Int = 0 protected fun separator(title: String) { println("\n\n--- ${title} ----------------------\n") @@ -63,8 +62,9 @@ internal final class Context(val config: KonanConfig, } fun printDescriptors() { + if (moduleDescriptor == null) return separator("Descriptors after: ${phase?.description}") - moduleDescriptor.deepPrint() + moduleDescriptor!!.deepPrint() } fun verifyIr() { @@ -125,6 +125,10 @@ internal final class Context(val config: KonanConfig, return config.configuration.getBoolean(KonanConfigKeys.PRINT_BITCODE) } + fun shouldProfilePhases(): Boolean { + return config.configuration.getBoolean(KonanConfigKeys.TIME_PHASES) + } + fun log(message: String) { if (phase?.verbose ?: false) { println(message) diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt index e345ea58195..faae3d2d54c 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfig.kt @@ -2,6 +2,7 @@ package org.jetbrains.kotlin.backend.konan import com.intellij.openapi.project.Project import org.jetbrains.kotlin.backend.konan.KonanPlatform +import org.jetbrains.kotlin.backend.konan.util.profile import org.jetbrains.kotlin.backend.konan.Distribution import org.jetbrains.kotlin.backend.konan.llvm.loadMetadata import org.jetbrains.kotlin.config.CommonConfigurationKeys @@ -36,14 +37,15 @@ class KonanConfig(val project: Project, val configuration: CompilerConfiguration for (path in libraries) { val filePath = File(path) if (!filePath.exists()) { - error("Path '" + path + "' does not exist"); + error("Path '" + path + "' does not exist") } - val moduleDescriptor = loadMetadata(configuration, filePath); - - allMetadata.add(moduleDescriptor); + profile("Loading ${filePath}") { + val moduleDescriptor = loadMetadata(configuration, filePath) + allMetadata.add(moduleDescriptor) + } } - return allMetadata; + return allMetadata } internal val moduleDescriptors: List by lazy { diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfigurationKeys.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfigurationKeys.kt index 7e28278e7f9..95ca1afc425 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfigurationKeys.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanConfigurationKeys.kt @@ -53,6 +53,8 @@ class KonanConfigKeys { = CompilerConfigurationKey.create("verbose backend phases"); val LIST_PHASES: CompilerConfigurationKey = CompilerConfigurationKey.create("list backend phases"); + val TIME_PHASES: CompilerConfigurationKey + = CompilerConfigurationKey.create("time backend phases"); } } diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanDriver.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanDriver.kt index ff83e454d96..f8d603f44bd 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanDriver.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanDriver.kt @@ -2,6 +2,7 @@ package org.jetbrains.kotlin.backend.konan import org.jetbrains.kotlin.analyzer.AnalysisResult import org.jetbrains.kotlin.backend.konan.llvm.emitLLVM +import org.jetbrains.kotlin.backend.konan.util.profile import org.jetbrains.kotlin.backend.konan.Context import org.jetbrains.kotlin.cli.common.CLICompiler import org.jetbrains.kotlin.cli.common.CLIConfigurationKeys @@ -43,20 +44,22 @@ public fun runTopLevelPhases(konanConfig: KonanConfig, environment: KotlinCoreEn val analyzerWithCompilerReport = AnalyzerWithCompilerReport(collector) - // Build AST and binding info. - analyzerWithCompilerReport.analyzeAndReport(environment.getSourceFiles(), - NativeAnalyzer(environment, environment.getSourceFiles(), konanConfig)) + val context = Context(konanConfig) + val phaser = PhaseManager(context) + + phaser.phase(KonanPhase.FRONTEND) { + // Build AST and binding info. + analyzerWithCompilerReport.analyzeAndReport(environment.getSourceFiles(), + NativeAnalyzer(environment, environment.getSourceFiles(), konanConfig)) + context.moduleDescriptor = analyzerWithCompilerReport.analysisResult.moduleDescriptor + } val bindingContext = analyzerWithCompilerReport.analysisResult.bindingContext - val moduleDescriptor = analyzerWithCompilerReport.analysisResult.moduleDescriptor - - val context = Context(konanConfig, bindingContext, moduleDescriptor) - val phaser = PhaseManager(context) phaser.phase(KonanPhase.PSI_TO_IR) { // Translate AST to high level IR. val translator = Psi2IrTranslator(Psi2IrConfiguration(false)) - val module = translator.generateModule( moduleDescriptor, + val module = translator.generateModule( context.moduleDescriptor!!, environment.getSourceFiles(), bindingContext) context.irModule = module diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanPhases.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanPhases.kt index 2c163eaf5ba..5df794ed9d3 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanPhases.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/KonanPhases.kt @@ -1,10 +1,12 @@ package org.jetbrains.kotlin.backend.konan import org.jetbrains.kotlin.backend.konan.Context +import org.jetbrains.kotlin.backend.konan.util.* enum class KonanPhase(val description: String, var enabled: Boolean = true, var verbose: Boolean = false) { + /* */ FRONTEND("Frontend builds AST"), /* */ PSI_TO_IR("Psi to IR conversion"), /* */ BACKEND("All backend"), /* ... */ LOWER("IR Lowering"), @@ -24,19 +26,28 @@ enum class KonanPhase(val description: String, object KonanPhases { val phases = KonanPhase.values().associate { it.name.toLowerCase() to it } - fun config(config: KonanConfig) { - val disabled = config.configuration.get(KonanConfigKeys.DISABLED_PHASES) - disabled?.forEach { phases[it]!!.enabled = false } - - val enabled = config.configuration.get(KonanConfigKeys.ENABLED_PHASES) - enabled?.forEach { phases[it]!!.enabled = true } - - val verbose = config.configuration.get(KonanConfigKeys.VERBOSE_PHASES) - verbose?.forEach { phases[it]!!.verbose = true } - - if (config.configuration.get(KonanConfigKeys.NOLINK) ?: false ) { - KonanPhase.LINKER.enabled = false + fun known(name: String): String { + if (phases[name] == null) { + error("Unknown phase: $name. Use -list to see the list of phases.") } + return name + } + + fun config(config: KonanConfig) { + with (config.configuration) { with (KonanConfigKeys) { + val disabled = get(DISABLED_PHASES) + disabled?.forEach { phases[known(it)]!!.enabled = false } + + val enabled = get(ENABLED_PHASES) + enabled?.forEach { phases[known(it)]!!.enabled = true } + + val verbose = get(VERBOSE_PHASES) + verbose?.forEach { phases[known(it)]!!.verbose = true } + + if (get(NOLINK) ?: false ) { + KonanPhase.LINKER.enabled = false + } + }} } fun list() { @@ -57,10 +68,13 @@ internal class PhaseManager(val context: Context) { val savePhase = context.phase context.phase = phase - - body() + context.depth ++ with (context) { + profileIf(shouldProfilePhases(), "Phase ${nTabs(depth)} ${phase.name}") { + body() + } + if (shouldVerifyDescriptors()) { verifyDescriptors() } @@ -82,6 +96,7 @@ internal class PhaseManager(val context: Context) { } } + context.depth -- context.phase = savePhase } } diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/descriptors/DeepPrintVisitor.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/descriptors/DeepPrintVisitor.kt index d482bc8b591..7730e7df0a4 100644 --- a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/descriptors/DeepPrintVisitor.kt +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/descriptors/DeepPrintVisitor.kt @@ -1,6 +1,7 @@ package org.jetbrains.kotlin.backend.konan.descriptors import org.jetbrains.kotlin.backend.konan.llvm.* +import org.jetbrains.kotlin.backend.konan.util.nTabs import org.jetbrains.kotlin.renderer.* import org.jetbrains.kotlin.descriptors.* @@ -20,7 +21,7 @@ public class DeepPrintVisitor(worker: DeclarationDescriptorVisitor public class PrintVisitor: DeclarationDescriptorVisitor { fun printDescriptor(descriptor: DeclarationDescriptor, amount: Int): Boolean { - println(String.format("%1$-${(amount+1)*4}s", "") + descriptor.toString()) + println("${nTabs(amount)} ${descriptor.toString()}") return true; } diff --git a/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/util/util.kt b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/util/util.kt new file mode 100644 index 00000000000..9c1eb21a457 --- /dev/null +++ b/backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/util/util.kt @@ -0,0 +1,22 @@ +package org.jetbrains.kotlin.backend.konan.util + +import kotlin.system.measureTimeMillis + +fun printMillisec(message: String, body: () -> Unit) { + val msec = measureTimeMillis{ + body() + } + println("$message: $msec msec") +} + +fun profile(message: String, body: () -> Unit) = profileIf( + System.getProperty("konan.profile")?.equals("true") ?: false, + message, body) + +fun profileIf(condition: Boolean, message: String, body: () -> Unit) = + if (condition) printMillisec(message, body) else body() + +fun nTabs(amount: Int): String { + return String.format("%1$-${(amount+1)*4}s", "") +} + diff --git a/cmd/konanc b/cmd/konanc index 7dc12106dc7..b17e994bc25 100755 --- a/cmd/konanc +++ b/cmd/konanc @@ -6,7 +6,6 @@ else JAVACMD=java fi [ -n "$JAVACMD" ] || JAVACMD=java -[ -n "$JAVA_OPTS" ] || JAVA_OPTS="-Xmx256M -Xms32M" declare -a java_args declare -a konan_args @@ -25,6 +24,12 @@ while [ $# -gt 0 ]; do echo "TODO: need to pass arguments to all the tools somehow." shift ;; + -time) + konan_args=("${konan_args[@]}" -time) + java_args=("${java_args[@]}" -agentlib:hprof=cpu=samples -Dkonan.profile=true) + JAVACMD="time $JAVACMD" + shift + ;; *) konan_args=("${konan_args[@]}" "$1") shift