diff --git a/compiler/fir/modularized-tests/tests/org/jetbrains/kotlin/fir/FirResolveModularizedTotalKotlinTest.kt b/compiler/fir/modularized-tests/tests/org/jetbrains/kotlin/fir/FirResolveModularizedTotalKotlinTest.kt index 1cb18370301..0a5dcf19baf 100644 --- a/compiler/fir/modularized-tests/tests/org/jetbrains/kotlin/fir/FirResolveModularizedTotalKotlinTest.kt +++ b/compiler/fir/modularized-tests/tests/org/jetbrains/kotlin/fir/FirResolveModularizedTotalKotlinTest.kt @@ -57,16 +57,7 @@ class FirResolveModularizedTotalKotlinTest : AbstractModularizedTest() { val builder = RawFirBuilder(session, stubMode = false) val totalTransformer = FirTotalResolveTransformer() - val firFiles = ktFiles.toList().mapNotNull { - var firFile: FirFile? = null - val time = measureNanoTime { - firFile = builder.buildFirFile(it) - (session.service() as FirProviderImpl).recordFile(firFile!!) - } - bench.countBuilder(builder, time) - firFile - }.toList() - + val firFiles = bench.buildFiles(builder, ktFiles) println("Raw FIR up, files: ${firFiles.size}") diff --git a/compiler/tests-common/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt similarity index 67% rename from compiler/tests-common/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt rename to compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt index 8d6cf7c21f4..cecce17072e 100644 --- a/compiler/tests-common/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt +++ b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/FirResolveBench.kt @@ -17,6 +17,7 @@ import org.jetbrains.kotlin.fir.visitors.FirTransformer import org.jetbrains.kotlin.fir.visitors.FirVisitorVoid import org.jetbrains.kotlin.psi.KtFile import org.jetbrains.kotlin.psi.psiUtil.startOffset +import org.jetbrains.kotlin.utils.addToStdlib.sumByLong import java.io.PrintStream import kotlin.math.max import kotlin.reflect.KClass @@ -35,8 +36,17 @@ private data class ErrorTypeReport(val report: String, var count: Int = 0) class FirResolveBench(val withProgress: Boolean) { - val timePerTransformer = mutableMapOf, Long>() - val counterPerTransformer = mutableMapOf, Long>() + + data class Measure( + var time: Long = 0, + var user: Long = 0, + var cpu: Long = 0, + var gcTime: Long = 0, + var gcCollections: Int = 0, + var files: Int = 0 + ) {} + + val timePerTransformer = mutableMapOf, Measure>() var resolvedTypes = 0 var errorTypes = 0 var unresolvedTypes = 0 @@ -51,9 +61,59 @@ class FirResolveBench(val withProgress: Boolean) { private val errorTypesReports = mutableMapOf() - fun countBuilder(builder: RawFirBuilder, time: Long) { - timePerTransformer.merge(builder::class, time) { a, b -> a + b } - counterPerTransformer.merge(builder::class, 1) { a, b -> a + b } + fun buildFiles( + builder: RawFirBuilder, + ktFiles: List + ): List { + return ktFiles.map { file -> + val before = vmStateSnapshot() + var firFile: FirFile? = null + val time = measureNanoTime { + firFile = builder.buildFirFile(file) + (builder.session.service() as FirProviderImpl).recordFile(firFile!!) + } + val after = vmStateSnapshot() + val diff = after - before + recordTime(builder::class, diff, time) + firFile!! + } + } + + private fun recordTime(stageClass: KClass<*>, diff: VMCounters, time: Long) { + timePerTransformer.computeIfAbsent(stageClass) { Measure() }.apply { + this.time += time + this.files += 1 + this.user += diff.userTime + this.cpu += diff.cpuTime + this.gcCollections += diff.gcInfo.values.sumBy { it.collections.toInt() } + this.gcTime += diff.gcInfo.values.sumByLong { it.gcTime } + } + } + + private fun runStage(transformer: FirTransformer, firFileSequence: Sequence) { + for (firFile in firFileSequence) { + var fail = false + val before = vmStateSnapshot() + val time = measureNanoTime { + try { + transformer.transformFile(firFile, null) + } catch (e: Throwable) { + val ktFile = firFile.psi as KtFile + println("Fail in file: ${ktFile.virtualFilePath}") + fail = true + fails += FailureInfo(transformer::class, e, ktFile.virtualFilePath) + //println(ktFile.text) + //throw e + } + } + if (!fail) { + val after = vmStateSnapshot() + val diff = after - before + recordTime(transformer::class, diff, time) + + } + //totalLength += StringBuilder().apply { FirRenderer(this).visitFile(firFile) }.length + } } fun processFiles( @@ -65,26 +125,7 @@ class FirResolveBench(val withProgress: Boolean) { for ((stage, transformer) in transformers.withIndex()) { println("Starting stage #$stage. $transformer") val firFileSequence = if (withProgress) firFiles.progress(" ~ ") else firFiles.asSequence() - for (firFile in firFileSequence) { - var fail = false - val time = measureNanoTime { - try { - transformer.transformFile(firFile, null) - } catch (e: Throwable) { - val ktFile = firFile.psi as KtFile - println("Fail in file: ${ktFile.virtualFilePath}") - fail = true - fails += FailureInfo(transformer::class, e, ktFile.virtualFilePath) - //println(ktFile.text) - //throw e - } - } - if (!fail) { - timePerTransformer.merge(transformer::class, time) { a, b -> a + b } - counterPerTransformer.merge(transformer::class, 1) { a, b -> a + b } - } - //totalLength += StringBuilder().apply { FirRenderer(this).visitFile(firFile) }.length - } + runStage(transformer, firFileSequence) checkFirProvidersConsistency(firFiles) } @@ -210,21 +251,52 @@ class FirResolveBench(val withProgress: Boolean) { stream.println("ERRONEOUSLY RESOLVED IMPLICIT TYPES: $implicitTypes (${implicitTypes percentOf resolvedTypes} of resolved)") stream.println("UNIQUE ERROR TYPES: ${errorTypesReports.size}") + printTable(stream) { + row { + cell("Stage", LEFT) + cells("Time", "Time per file", "Files: OK/E/T", "CPU", "User", "GC", "GC count") + } + separator() + timePerTransformer.forEach { (transformer, measure) -> + val time = measure.time + val counter = measure.files + row { + cell(transformer.simpleName.toString(), LEFT) + timeCell(time, fractionDigits = 0) + timeCell(time / counter) + cell("$counter/${fileCount - counter}/$fileCount") + timeCell(measure.cpu, fractionDigits = 0) + timeCell(measure.user) + timeCell(measure.gcTime, inputUnit = TableTimeUnit.MS) + cell(measure.gcCollections.toString()) + } + } - var totalTime = 0L - var totalFiles = 0L + if (timePerTransformer.keys.size > 0) { + separator() + val totalTime = timePerTransformer.values.sumByLong { it.time } + val totalCpuTime = timePerTransformer.values.sumByLong { it.cpu } + val totalUserTime = timePerTransformer.values.sumByLong { it.user } + val totalGcTime = timePerTransformer.values.sumByLong { it.gcTime } + val totalGcCollections = timePerTransformer.values.sumBy { it.gcCollections } + val averageFiles = timePerTransformer.values.map { it.files }.average().toLong() + + + row { + cell("Total", LEFT) + timeCell(totalTime, fractionDigits = 0) + timeCell(totalTime / averageFiles) + cell("$averageFiles") + cell("$averageFiles") + timeCell(totalCpuTime, fractionDigits = 0) + timeCell(totalUserTime) + timeCell(totalGcTime, inputUnit = TableTimeUnit.MS) + cell(totalGcCollections.toString()) + } + } - timePerTransformer.forEach { (transformer, time) -> - val counter = counterPerTransformer[transformer]!! - stream.println("${transformer.simpleName}, TIME: ${time * 1e-6} ms, TIME PER FILE: ${(time / counter) * 1e-6} ms, FILES: OK/E/T $counter/${fileCount - counter}/$fileCount") - totalTime += time - totalFiles += counter } - if (counterPerTransformer.keys.size > 0) { - totalFiles /= counterPerTransformer.keys.size - stream.println("Total, TIME: ${totalTime * 1e-6} ms, TIME PER FILE: ${(totalTime / totalFiles) * 1e-6} ms") - } } } diff --git a/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/TableRendering.kt b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/TableRendering.kt new file mode 100644 index 00000000000..98600c5d2ee --- /dev/null +++ b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/TableRendering.kt @@ -0,0 +1,149 @@ +/* + * Copyright 2010-2019 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. + */ + +package org.jetbrains.kotlin.fir + +import java.text.DecimalFormat + +class RTableContext { + val data: MutableList = mutableListOf() + var cols = 0 + fun row(names: List) = row(names.map { Cell(it) }) + + sealed class Row { + class Data(val cells: List) : Row() + class Separator() : Row() + } + + @JvmName("rowCells") + fun row(cells: List) { + cols = maxOf(cells.size, cols) + data += Row.Data(cells) + } + + fun row(vararg names: String) { + row(listOf(*names)) + } + + fun separator() { + data += Row.Separator() + } + + inner class RTableRowContext() { + val rowData = mutableListOf() + val LEFT = false + val RIGHT = true + fun cell(text: String?, align: Boolean = RIGHT) { + rowData += Cell(text.toString(), align) + } + + fun cells(texts: List, align: Boolean = RIGHT) { + rowData += texts.map { Cell(it, align) } + } + + fun cells(vararg texts: String, align: Boolean = RIGHT) { + cells(listOf(*texts), align) + } + } + + inline fun row(body: RTableRowContext.() -> Unit) { + val ctx = RTableRowContext() + ctx.body() + row(ctx.rowData) + } + + data class Cell(val text: String, val alignRight: Boolean = true) { + fun padText(size: Int): String { + return if (alignRight) { + text.padStart(size) + } else { + text.padEnd(size) + } + } + } + + fun printout(out: Appendable) { + val colSize = IntArray(cols) { index -> + data.filterIsInstance().fold(0) { acc, row -> maxOf(acc, row.cells[index].text.length) } + } + + + fun appendHLine(prefix: String, sep: String, postfix: String) { + out.append(prefix) + for ((index, size) in colSize.withIndex()) { + if (index != 0) { + out.append(sep) + out.append(HLINE) + } + out.append(HLINE.repeat(size)) + } + out.append(postfix) + out.appendln() + } + + appendHLine(CORNER_LU, TOP_T, CORNER_RU) + for (row in data) { + when (row) { + is Row.Data -> { + out.append(VLINE) + for ((index, cell) in row.cells.withIndex()) { + out.append(cell.padText(colSize[index])) + out.append(VLINE) + out.append(" ") + } + out.appendln() + } + is Row.Separator -> { + appendHLine(LEFT_T, CROSS, RIGHT_T) + } + } + + } + appendHLine(CORNER_LD, BOT_T, CORNER_RD) + } + + companion object { + private const val CROSS = "┼" + private const val VLINE = "│" + private const val HLINE = "─" + private const val CORNER_LU = "┌" + private const val CORNER_RU = "┐" + private const val CORNER_LD = "└" + private const val CORNER_RD = "┘" + private const val LEFT_T = "├" + private const val RIGHT_T = "┤" + private const val TOP_T = "┬" + private const val BOT_T = "┴" + } +} + + +internal enum class TableTimeUnit(val postfixText: String, val nsMultiplier: Double, val fractionDigits: Int) { + NS("ns", 1.0, 0), + MICS("mcs", 1e-3, 3), + MS("ms", 1e-6, 6), + S("s", 1e-9, 9); + + fun convert(value: Long, from: TableTimeUnit): Double { + return value / from.nsMultiplier * this.nsMultiplier + } +} + +internal inline fun RTableContext.RTableRowContext.timeCell( + time: Long, + outputUnit: TableTimeUnit = TableTimeUnit.MS, + inputUnit: TableTimeUnit = TableTimeUnit.NS, + fractionDigits: Int = outputUnit.fractionDigits +) { + val df = DecimalFormat() + df.maximumFractionDigits = fractionDigits + df.isGroupingUsed = true + + cell("${df.format(outputUnit.convert(time, inputUnit))} ${outputUnit.postfixText}") +} + +internal inline fun printTable(out: Appendable = System.out, body: RTableContext.() -> Unit) { + RTableContext().apply(body).printout(out) +} \ No newline at end of file diff --git a/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/VMCounters.kt b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/VMCounters.kt new file mode 100644 index 00000000000..3adf37967bf --- /dev/null +++ b/compiler/fir/resolve/tests/org/jetbrains/kotlin/fir/VMCounters.kt @@ -0,0 +1,58 @@ +/* + * Copyright 2010-2019 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. + */ + +package org.jetbrains.kotlin.fir + +import org.jetbrains.kotlin.daemon.common.threadCpuTime +import org.jetbrains.kotlin.daemon.common.threadUserTime +import sun.management.ManagementFactoryHelper + + +data class GCInfo(val name: String, val gcTime: Long, val collections: Long) { + operator fun minus(other: GCInfo): GCInfo { + return this.copy( + gcTime = gcTime - other.gcTime, + collections = collections - other.collections + ) + } +} + +data class VMCounters(val userTime: Long, val cpuTime: Long, val gcInfo: Map) { + + + operator fun minus(other: VMCounters): VMCounters { + return VMCounters( + userTime - other.userTime, + cpuTime - other.cpuTime, + merge(gcInfo, other.gcInfo) { a, b -> a - b } + ) + } + +} + + +private fun merge(first: Map, second: Map, valueOp: (V, V) -> V): Map { + val result = first.toMutableMap() + for ((k, v) in second) { + result.merge(k, v, valueOp) + } + return result +} + +object Init { + init { + ManagementFactoryHelper.getThreadMXBean().isThreadCpuTimeEnabled = true + } +} + +fun vmStateSnapshot(): VMCounters { + Init + val threadMXBean = ManagementFactoryHelper.getThreadMXBean() + + return VMCounters( + threadMXBean.threadUserTime(), threadMXBean.threadCpuTime(), + ManagementFactoryHelper.getGarbageCollectorMXBeans().associate { it.name to GCInfo(it.name, it.collectionTime, it.collectionCount) } + ) +} \ No newline at end of file