[IR] Rewrote debug output using Context.log

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

@@ -43,9 +43,6 @@ import org.jetbrains.kotlin.backend.konan.llvm.coverage.CoverageManager
 import org.jetbrains.kotlin.ir.descriptors.WrappedSimpleFunctionDescriptor
 import org.jetbrains.kotlin.ir.symbols.IrSymbol
 import org.jetbrains.kotlin.ir.symbols.impl.IrFieldSymbolImpl
-import org.jetbrains.kotlin.ir.types.IrType
-import org.jetbrains.kotlin.ir.types.defaultType
-import org.jetbrains.kotlin.ir.types.makeNullable
 import org.jetbrains.kotlin.name.FqName
 import org.jetbrains.kotlin.konan.library.KonanLibraryLayout
 import org.jetbrains.kotlin.library.SerializedIrModule
@@ -429,3 +426,12 @@ private fun MemberScope.getContributedClassifier(name: String) =
 
 private fun MemberScope.getContributedFunctions(name: String) =
         this.getContributedFunctions(Name.identifier(name), NoLookupLocation.FROM_BUILTINS)
+
+internal class ContextLogger(val context: Context) {
+    operator fun String.unaryPlus() = context.log { this }
+}
+
+internal fun Context.logMultiple(messageBuilder: ContextLogger.() -> Unit) {
+    if (!inVerbosePhase) return
+    with(ContextLogger(this)) { messageBuilder() }
+}

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/descriptors/ClassLayoutBuilder.kt

@@ -262,19 +262,12 @@ internal class GlobalHierarchyAnalysis(val context: Context, val irModule: IrMod
 }
 
 internal class ClassLayoutBuilder(val irClass: IrClass, val context: Context, val isLowered: Boolean) {
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     val vtableEntries: List<OverriddenFunctionInfo> by lazy {
-
         assert(!irClass.isInterface)
 
-        DEBUG_OUTPUT(0) {
+        context.logMultiple {
-            println()
+            +""
-            println("BUILDING vTable for ${irClass.render()}")
+            +"BUILDING vTable for ${irClass.render()}"
         }
 
         val superVtableEntries = if (irClass.isSpecialClassWithNoSupertypes()) {
@@ -288,17 +281,17 @@ internal class ClassLayoutBuilder(val irClass: IrClass, val context: Context, va
         val newVtableSlots = mutableListOf<OverriddenFunctionInfo>()
         val overridenVtableSlots = mutableMapOf<IrSimpleFunction, OverriddenFunctionInfo>()
 
-        DEBUG_OUTPUT(0) {
+        context.logMultiple {
-            println()
+            +""
-            println("SUPER vTable:")
+            +"SUPER vTable:"
-            superVtableEntries.forEach { println("    ${it.overriddenFunction.render()} -> ${it.function.render()}") }
+            superVtableEntries.forEach { +"    ${it.overriddenFunction.render()} -> ${it.function.render()}" }
 
-            println()
+            +""
-            println("METHODS:")
+            +"METHODS:"
-            methods.forEach { println("    ${it.render()}") }
+            methods.forEach { +"    ${it.render()}" }
 
-            println()
+            +""
-            println("BUILDING INHERITED vTable")
+            +"BUILDING INHERITED vTable"
         }
 
         val superVtableMap = superVtableEntries.groupBy { it.function }
@@ -316,13 +309,9 @@ internal class ClassLayoutBuilder(val irClass: IrClass, val context: Context, va
         }
         val inheritedVtableSlots = superVtableEntries.map { superMethod ->
             overridenVtableSlots[superMethod.overriddenFunction]?.also {
-                DEBUG_OUTPUT(0) {
+                context.log { "Taking overridden ${superMethod.overriddenFunction.render()} -> ${it.function.render()}" }
-                    println("Taking overridden ${superMethod.overriddenFunction.render()} -> ${it.function.render()}")
-                }
             } ?: superMethod.also {
-                DEBUG_OUTPUT(0) {
+                context.log { "Taking super ${superMethod.overriddenFunction.render()} -> ${superMethod.function.render()}" }
-                    println("Taking super ${superMethod.overriddenFunction.render()} -> ${superMethod.function.render()}")
-                }
             }
         }
 
@@ -336,15 +325,15 @@ internal class ClassLayoutBuilder(val irClass: IrClass, val context: Context, va
             .distinctBy { it.function to it.bridgeDirections }
             .filter { it.function.isOverridable }
 
-        DEBUG_OUTPUT(0) {
+        context.logMultiple {
-            println()
+            +""
-            println("INHERITED vTable slots:")
+            +"INHERITED vTable slots:"
-            inheritedVtableSlots.forEach { println("    ${it.overriddenFunction.render()} -> ${it.function.render()}") }
+            inheritedVtableSlots.forEach { +"    ${it.overriddenFunction.render()} -> ${it.function.render()}" }
 
-            println()
+            +""
-            println("MY OWN vTable slots:")
+            +"MY OWN vTable slots:"
-            filteredNewVtableSlots.forEach { println("    ${it.overriddenFunction.render()} -> ${it.function.render()} ${it.function}") }
+            filteredNewVtableSlots.forEach { +"    ${it.overriddenFunction.render()} -> ${it.function.render()} ${it.function}" }
-            println("DONE vTable for ${irClass.render()}")
+            +"DONE vTable for ${irClass.render()}"
         }
 
         inheritedVtableSlots + filteredNewVtableSlots.sortedBy { it.overriddenFunction.uniqueId }

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/CallGraphBuilder.kt

@@ -59,12 +59,6 @@ internal class CallGraphBuilder(
         val nonDevirtualizedCallSitesUnfoldFactor: Int
 ) {
 
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     private val devirtualizedCallSites = devirtualizationAnalysisResult.devirtualizedCallSites
 
     private fun DataFlowIR.FunctionSymbol.resolved(): DataFlowIR.FunctionSymbol {

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/DFGBuilder.kt

@@ -13,7 +13,6 @@ import org.jetbrains.kotlin.backend.common.pop
 import org.jetbrains.kotlin.backend.common.push
 import org.jetbrains.kotlin.backend.konan.*
 import org.jetbrains.kotlin.backend.konan.descriptors.allOverriddenFunctions
-import org.jetbrains.kotlin.backend.konan.descriptors.target
 import org.jetbrains.kotlin.backend.konan.ir.*
 import org.jetbrains.kotlin.backend.konan.llvm.functionName
 import org.jetbrains.kotlin.backend.konan.llvm.localHash
@@ -177,12 +176,6 @@ internal class ModuleDFG(val functions: Map<DataFlowIR.FunctionSymbol, DataFlowI
 
 internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFragment) {
 
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     private val TAKE_NAMES = true // Take fqNames for all functions and types (for debug purposes).
 
     private inline fun takeName(block: () -> String) = if (TAKE_NAMES) block() else null
@@ -211,9 +204,9 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
                 assert (body != null || declaration.constructedClass.isNonGeneratedAnnotation()) {
                     "Non-annotation class constructor has empty body"
                 }
-                DEBUG_OUTPUT(0) {
+                context.logMultiple {
-                    println("Analysing function ${declaration.descriptor}")
+                    +"Analysing function ${declaration.descriptor}"
-                    println("IR: ${ir2stringWhole(declaration)}")
+                    +"IR: ${ir2stringWhole(declaration)}"
                 }
                 analyze(declaration, body)
             }
@@ -224,9 +217,9 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
                     // External function or intrinsic.
                     symbolTable.mapFunction(declaration)
                 } else {
-                    DEBUG_OUTPUT(0) {
+                    context.logMultiple {
-                        println("Analysing function ${declaration.descriptor}")
+                        +"Analysing function ${declaration.descriptor}"
-                        println("IR: ${ir2stringWhole(declaration)}")
+                        +"IR: ${ir2stringWhole(declaration)}"
                     }
                     analyze(declaration, body)
                 }
@@ -235,9 +228,9 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
             override fun visitField(declaration: IrField) {
                 if (declaration.parent is IrFile)
                     declaration.initializer?.let {
-                        DEBUG_OUTPUT(0) {
+                        context.logMultiple {
-                            println("Analysing global field ${declaration.descriptor}")
+                            +"Analysing global field ${declaration.descriptor}"
-                            println("IR: ${ir2stringWhole(declaration)}")
+                            +"IR: ${ir2stringWhole(declaration)}"
                         }
                         analyze(declaration, IrSetFieldImpl(it.startOffset, it.endOffset, declaration.symbol, null,
                                 it.expression, context.irBuiltIns.unitType))
@@ -249,29 +242,25 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
                 val visitor = ElementFinderVisitor()
                 body?.acceptVoid(visitor)
 
-                DEBUG_OUTPUT(0) {
+                context.logMultiple {
-                    println("FIRST PHASE")
+                    +"FIRST PHASE"
-                    visitor.variableValues.elementData.forEach { t, u ->
+                    visitor.variableValues.elementData.forEach { (t, u) ->
-                        println("VAR $t [LOOP ${u.loop}]:")
+                        +"VAR $t [LOOP ${u.loop}]:"
-                        u.values.forEach {
+                        u.values.forEach { +"    ${ir2stringWhole(it)}" }
-                            println("    ${ir2stringWhole(it)}")
-                        }
                     }
                     visitor.expressions.forEach { t ->
-                        println("EXP [LOOP ${t.value}] ${ir2stringWhole(t.key)}")
+                        +"EXP [LOOP ${t.value}] ${ir2stringWhole(t.key)}"
                     }
                 }
 
                 // Compute transitive closure of possible values for variables.
                 visitor.variableValues.computeClosure()
 
-                DEBUG_OUTPUT(0) {
+                context.logMultiple {
-                    println("SECOND PHASE")
+                    +"SECOND PHASE"
-                    visitor.variableValues.elementData.forEach { t, u ->
+                    visitor.variableValues.elementData.forEach { (t, u) ->
-                        println("VAR $t [LOOP ${u.loop}]:")
+                        +"VAR $t [LOOP ${u.loop}]:"
-                        u.values.forEach {
+                        u.values.forEach { +"    ${ir2stringWhole(it)}" }
-                            println("    ${ir2stringWhole(it)}")
-                        }
                     }
                 }
 
@@ -279,27 +268,28 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
                         declaration, visitor.expressions, visitor.parentLoops, visitor.returnValues,
                         visitor.thrownValues, visitor.catchParameters).build()
 
-                DEBUG_OUTPUT(0) {
+                context.logMultiple {
-                    function.debugOutput()
+                    +function.debugString()
+                    +""
                 }
 
-                functions.put(function.symbol, function)
+                functions[function.symbol] = function
             }
         }, data = null)
 
-        DEBUG_OUTPUT(1) {
+        context.logMultiple {
-            println("SYMBOL TABLE:")
+            +"SYMBOL TABLE:"
             symbolTable.classMap.forEach { irClass, type ->
-                println("    DESCRIPTOR: ${irClass.descriptor}")
+                +"    DESCRIPTOR: ${irClass.descriptor}"
-                println("    TYPE: $type")
+                +"    TYPE: $type"
                 if (type !is DataFlowIR.Type.Declared)
                     return@forEach
-                println("        SUPER TYPES:")
+                +"        SUPER TYPES:"
-                type.superTypes.forEach { println("            $it") }
+                type.superTypes.forEach { +"            $it" }
-                println("        VTABLE:")
+                +"        VTABLE:"
-                type.vtable.forEach { println("            $it") }
+                type.vtable.forEach { +"            $it" }
-                println("        ITABLE:")
+                +"        ITABLE:"
-                type.itable.forEach { println("            ${it.key} -> ${it.value}") }
+                type.itable.forEach { +"            ${it.key} -> ${it.value}" }
             }
         }
 
@@ -618,9 +608,9 @@ internal class ModuleDFGBuilder(val context: Context, val irModule: IrModuleFrag
                 return variables[valueDeclaration]!!
             }
             return nodes.getOrPut(expression) {
-                DEBUG_OUTPUT(0) {
+                context.logMultiple {
-                    println("Converting expression")
+                    +"Converting expression"
-                    println(ir2stringWhole(expression))
+                    +ir2stringWhole(expression)
                 }
                 val values = mutableListOf<IrExpression>()
                 val edges = mutableListOf<DataFlowIR.Edge>()

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/DataFlowIR.kt

@@ -8,7 +8,6 @@ package org.jetbrains.kotlin.backend.konan.optimizations
 import org.jetbrains.kotlin.backend.konan.*
 import org.jetbrains.kotlin.backend.konan.descriptors.isAbstract
 import org.jetbrains.kotlin.backend.konan.descriptors.isBuiltInOperator
-import org.jetbrains.kotlin.backend.konan.descriptors.target
 import org.jetbrains.kotlin.backend.konan.ir.allParameters
 import org.jetbrains.kotlin.backend.konan.ir.isOverridableOrOverrides
 import org.jetbrains.kotlin.backend.konan.llvm.functionName
@@ -17,6 +16,7 @@ import org.jetbrains.kotlin.backend.konan.llvm.localHash
 import org.jetbrains.kotlin.backend.konan.llvm.symbolName
 import org.jetbrains.kotlin.backend.konan.lower.DECLARATION_ORIGIN_BRIDGE_METHOD
 import org.jetbrains.kotlin.backend.konan.lower.bridgeTarget
+import org.jetbrains.kotlin.backend.konan.optimizations.DataFlowIR.Function.Companion.appendCastTo
 import org.jetbrains.kotlin.descriptors.Modality
 import org.jetbrains.kotlin.descriptors.ModuleDescriptor
 import org.jetbrains.kotlin.ir.IrElement
@@ -285,17 +285,19 @@ internal object DataFlowIR {
 
     class Function(val symbol: FunctionSymbol, val body: FunctionBody) {
 
-        fun debugOutput() {
+        fun debugOutput() = println(debugString())
-            println("FUNCTION $symbol")
+
-            println("Params: ${symbol.parameters.contentToString()}")
+        fun debugString() = buildString {
+            appendLine("FUNCTION $symbol")
+            appendLine("Params: ${symbol.parameters.contentToString()}")
             val nodes = listOf(body.rootScope) + body.allScopes.flatMap { it.nodes }
             val ids = nodes.withIndex().associateBy({ it.value }, { it.index })
             nodes.forEach {
-                println("    NODE #${ids[it]!!}")
+                appendLine("    NODE #${ids[it]!!}")
-                printNode(it, ids)
+                appendLine(nodeToString(it, ids))
             }
-            println("    RETURNS")
+            appendLine("    RETURNS")
-            printNode(body.returns, ids)
+            append(nodeToString(body.returns, ids))
         }
 
         companion object {
@@ -303,169 +305,125 @@ internal object DataFlowIR {
 
             fun nodeToString(node: Node, ids: Map<Node, Int>) = when (node) {
                 is Node.Const ->
-                    "        CONST ${node.type}\n"
+                    "        CONST ${node.type}"
 
                 Node.Null ->
-                    "        NULL\n"
+                    "        NULL"
 
                 is Node.Parameter ->
-                    "        PARAM ${node.index}\n"
+                    "        PARAM ${node.index}"
 
                 is Node.Singleton ->
-                    "        SINGLETON ${node.type}\n"
+                    "        SINGLETON ${node.type}"
 
                 is Node.AllocInstance ->
-                    "        ALLOC INSTANCE ${node.type}\n"
+                    "        ALLOC INSTANCE ${node.type}"
 
                 is Node.FunctionReference ->
-                    "        FUNCTION REFERENCE ${node.symbol}\n"
+                    "        FUNCTION REFERENCE ${node.symbol}"
 
-                is Node.StaticCall -> {
+                is Node.StaticCall -> buildString {
-                    buildString {
+                    append("        STATIC CALL ${node.callee}. Return type = ${node.returnType}")
-                        appendLine("        STATIC CALL ${node.callee}. Return type = ${node.returnType}")
+                    appendList(node.arguments) {
-                        node.arguments.forEach {
+                        append("            ARG #${ids[it.node]!!}")
-                            append("            ARG #${ids[it.node]!!}")
+                        appendCastTo(it.castToType)
-                            if (it.castToType == null)
-                                appendLine()
-                            else
-                                appendLine(" CASTED TO ${it.castToType}")
-                        }
                     }
                 }
 
-                is Node.VtableCall -> {
+                is Node.VtableCall -> buildString {
-                    buildString {
+                    appendLine("        VIRTUAL CALL ${node.callee}. Return type = ${node.returnType}")
-                        appendLine("        VIRTUAL CALL ${node.callee}. Return type = ${node.returnType}")
+                    appendLine("            RECEIVER: ${node.receiverType}")
-                        appendLine("            RECEIVER: ${node.receiverType}")
+                    append("            VTABLE INDEX: ${node.calleeVtableIndex}")
-                        appendLine("            VTABLE INDEX: ${node.calleeVtableIndex}")
+                    appendList(node.arguments) {
-                        node.arguments.forEach {
+                        append("            ARG #${ids[it.node]!!}")
-                            append("            ARG #${ids[it.node]!!}")
+                        appendCastTo(it.castToType)
-                            if (it.castToType == null)
-                                appendLine()
-                            else
-                                appendLine(" CASTED TO ${it.castToType}")
-                        }
                     }
                 }
 
-                is Node.ItableCall -> {
+                is Node.ItableCall -> buildString {
-                    buildString {
+                    appendLine("        INTERFACE CALL ${node.callee}. Return type = ${node.returnType}")
-                        appendLine("        INTERFACE CALL ${node.callee}. Return type = ${node.returnType}")
+                    appendLine("            RECEIVER: ${node.receiverType}")
-                        appendLine("            RECEIVER: ${node.receiverType}")
+                    append("            METHOD HASH: ${node.calleeHash}")
-                        appendLine("            METHOD HASH: ${node.calleeHash}")
+                    appendList(node.arguments) {
-                        node.arguments.forEach {
+                        append("            ARG #${ids[it.node]!!}")
-                            append("            ARG #${ids[it.node]!!}")
+                        appendCastTo(it.castToType)
-                            if (it.castToType == null)
-                                appendLine()
-                            else
-                                appendLine(" CASTED TO ${it.castToType}")
-                        }
                     }
                 }
 
-                is Node.NewObject -> {
+                is Node.NewObject -> buildString {
-                    buildString {
+                    appendLine("        NEW OBJECT ${node.callee}")
-                        appendLine("        NEW OBJECT ${node.callee}")
+                    append("        CONSTRUCTED TYPE ${node.constructedType}")
-                        appendLine("        CONSTRUCTED TYPE ${node.constructedType}")
+                    appendList(node.arguments) {
-                        node.arguments.forEach {
+                        append("            ARG #${ids[it.node]!!}")
-                            append("            ARG #${ids[it.node]!!}")
+                        appendCastTo(it.castToType)
-                            if (it.castToType == null)
-                                appendLine()
-                            else
-                                appendLine(" CASTED TO ${it.castToType}")
-                        }
                     }
                 }
 
-                is Node.FieldRead -> {
+                is Node.FieldRead -> buildString {
-                    buildString {
+                    appendLine("        FIELD READ ${node.field}")
-                        appendLine("        FIELD READ ${node.field}")
+                    append("            RECEIVER #${node.receiver?.node?.let { ids[it]!! } ?: "null"}")
-                        append("            RECEIVER #${node.receiver?.node?.let { ids[it]!! } ?: "null"}")
+                    appendCastTo(node.receiver?.castToType)
-                        if (node.receiver?.castToType == null)
+                }
-                            appendLine()
+
-                        else
+                is Node.FieldWrite -> buildString {
-                            appendLine(" CASTED TO ${node.receiver.castToType}")
+                    appendLine("        FIELD WRITE ${node.field}")
+                    append("            RECEIVER #${node.receiver?.node?.let { ids[it]!! } ?: "null"}")
+                    appendCastTo(node.receiver?.castToType)
+                    appendLine()
+                    append("            VALUE #${ids[node.value.node]!!}")
+                    appendCastTo(node.value.castToType)
+                }
+
+                is Node.ArrayRead -> buildString {
+                    appendLine("        ARRAY READ")
+                    append("            ARRAY #${ids[node.array.node]}")
+                    appendCastTo(node.array.castToType)
+                    appendLine()
+                    append("            INDEX #${ids[node.index.node]!!}")
+                    appendCastTo(node.index.castToType)
+                }
+
+                is Node.ArrayWrite -> buildString {
+                    appendLine("        ARRAY WRITE")
+                    append("            ARRAY #${ids[node.array.node]}")
+                    appendCastTo(node.array.castToType)
+                    appendLine()
+                    append("            INDEX #${ids[node.index.node]!!}")
+                    appendCastTo(node.index.castToType)
+                    appendLine()
+                    append("            VALUE #${ids[node.value.node]!!}")
+                    appendCastTo(node.value.castToType)
+                }
+
+                is Node.Variable -> buildString {
+                    append("       ${node.kind}")
+                    appendList(node.values) {
+                        append("            VAL #${ids[it.node]!!}")
+                        appendCastTo(it.castToType)
                     }
                 }
 
-                is Node.FieldWrite -> {
+                is Node.Scope -> buildString {
-                    buildString {
+                    append("       SCOPE ${node.depth}")
-                        appendLine("        FIELD WRITE ${node.field}")
+                    appendList(node.nodes.toList()) {
-                        append("            RECEIVER #${node.receiver?.node?.let { ids[it]!! } ?: "null"}")
+                        append("            SUBNODE #${ids[it]!!}")
-                        if (node.receiver?.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.receiver.castToType}")
-                        print("            VALUE #${ids[node.value.node]!!}")
-                        if (node.value.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.value.castToType}")
                     }
                 }
 
-                is Node.ArrayRead -> {
+                else -> "        UNKNOWN: ${node::class.java}"
-                    buildString {
+            }
-                        appendLine("        ARRAY READ")
-                        append("            ARRAY #${ids[node.array.node]}")
-                        if (node.array.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.array.castToType}")
-                        append("            INDEX #${ids[node.index.node]!!}")
-                        if (node.index.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.index.castToType}")
-                    }
-                }
 
-                is Node.ArrayWrite -> {
+            private fun <T> StringBuilder.appendList(list: List<T>, itemPrinter: StringBuilder.(T) -> Unit) {
-                    buildString {
+                if (list.isEmpty()) return
-                        appendLine("        ARRAY WRITE")
+                for (i in list.indices) {
-                        append("            ARRAY #${ids[node.array.node]}")
+                    appendLine()
-                        if (node.array.castToType == null)
+                    itemPrinter(list[i])
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.array.castToType}")
-                        append("            INDEX #${ids[node.index.node]!!}")
-                        if (node.index.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.index.castToType}")
-                        print("            VALUE #${ids[node.value.node]!!}")
-                        if (node.value.castToType == null)
-                            appendLine()
-                        else
-                            appendLine(" CASTED TO ${node.value.castToType}")
-                    }
                 }
+            }
 
-                is Node.Variable -> {
+            private fun StringBuilder.appendCastTo(type: Type?) {
-                    buildString {
+                if (type != null)
-                        appendLine("       ${node.kind}")
+                    append(" CASTED TO ${type}")
-                        node.values.forEach {
-                            append("            VAL #${ids[it.node]!!}")
-                            if (it.castToType == null)
-                                appendLine()
-                            else
-                                appendLine(" CASTED TO ${it.castToType}")
-                        }
-                    }
-                }
-
-                is Node.Scope -> {
-                    val result = StringBuilder()
-                    result.appendLine("       SCOPE ${node.depth}")
-                    node.nodes.forEach {
-                        result.appendLine("            SUBNODE #${ids[it]!!}")
-                    }
-                    result.toString()
-                }
-
-                else -> {
-                    "        UNKNOWN: ${node::class.java}\n"
-                }
             }
         }
     }

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/Devirtualization.kt

@@ -54,12 +54,6 @@ inline fun BitSet.forEachBit(block: (Int) -> Unit) {
 // See http://web.cs.ucla.edu/~palsberg/tba/papers/sundaresan-et-al-oopsla00.pdf for details.
 internal object Devirtualization {
 
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     private val TAKE_NAMES = false // Take fqNames for all functions and types (for debug purposes).
 
     private inline fun takeName(block: () -> String) = if (TAKE_NAMES) block() else null
@@ -276,7 +270,7 @@ internal object Devirtualization {
 
         fun BitSet.copy() = BitSet(this.size()).apply { this.or(this@copy) }
 
-        fun printPathToType(reversedEdges: IntArray, node: Node, type: Int) {
+        fun logPathToType(reversedEdges: IntArray, node: Node, type: Int) {
             val nodes = constraintGraph.nodes
             val visited = BitSet()
             val prev = mutableMapOf<Node, Node>()
@@ -322,11 +316,11 @@ internal object Devirtualization {
             try {
                 var cur: Node = source
                 do {
-                    println("    #${cur.id}")
+                    context.log { "    #${cur.id}" }
                     cur = prev[cur]!!
                 } while (cur != node)
             } catch (t: Throwable) {
-                println("Unable to print path")
+                context.log { "Unable to print path" }
             }
         }
 
@@ -416,6 +410,9 @@ internal object Devirtualization {
             }
         }
 
+        private fun DataFlowIR.Node.VirtualCall.debugString() =
+                irCallSite?.let { ir2stringWhole(it).trimEnd() } ?: this.toString()
+
         fun analyze(): AnalysisResult {
             val functions = moduleDFG.functions + externalModulesDFG.functionDFGs
             assert(DataFlowIR.Type.Virtual !in symbolTable.classMap.values) {
@@ -435,21 +432,20 @@ internal object Devirtualization {
 
             val (instantiatingClasses, directEdges, reversedEdges) = buildConstraintGraph(nodesMap, functions, typeHierarchy, rootSet)
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("FULL CONSTRAINT GRAPH")
+                +"FULL CONSTRAINT GRAPH"
                 constraintGraph.nodes.forEach {
-                    println("    NODE #${it.id}")
+                    +"    NODE #${it.id}"
-                    directEdges.forEachEdge(it.id) {
+                    directEdges.forEachEdge(it.id) { +"        EDGE: #${it}z" }
-                        println("        EDGE: #${it}z")
-                    }
                     it.directCastEdges?.forEach {
-                        println("        CAST EDGE: #${it.node.id}z casted to ${it.suitableTypes.format(allTypes)}")
+                        +"        CAST EDGE: #${it.node.id}z casted to ${it.suitableTypes.format(allTypes)}"
                     }
                     allTypes.forEachIndexed { index, type ->
                         if (it.types[index])
-                            println("        TYPE: $type")
+                            +"        TYPE: $type"
                     }
                 }
+                +""
             }
 
             constraintGraph.nodes.forEach {
@@ -459,22 +455,24 @@ internal object Devirtualization {
                 }
             }
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("CONSTRAINT GRAPH: ${constraintGraph.nodes.size} nodes, " +
+                val edgesCount = constraintGraph.nodes.sumBy {
-                    "${constraintGraph.nodes.sumBy { (directEdges[it.id + 1] - directEdges[it.id]) + (it.directCastEdges?.size ?: 0) } } edges")
+                    (directEdges[it.id + 1] - directEdges[it.id]) + (it.directCastEdges?.size ?: 0)
+                }
+                +"CONSTRAINT GRAPH: ${constraintGraph.nodes.size} nodes, $edgesCount edges"
+                +""
             }
 
             val condensation = CondensationBuilder(directEdges, reversedEdges).build()
             val topologicalOrder = condensation.topologicalOrder.map { constraintGraph.nodes[it] }
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("CONDENSATION")
+                +"CONDENSATION"
                 topologicalOrder.forEachIndexed { index, multiNode ->
-                    println("    MULTI-NODE #$index")
+                    +"    MULTI-NODE #$index"
-                    condensation.forEachNode(multiNode) {
+                    condensation.forEachNode(multiNode) { +"        #${it.id}: ${it.toString(allTypes)}" }
-                        println("        #${it.id}: ${it.toString(allTypes)}")
-                    }
                 }
+                +""
             }
 
             topologicalOrder.forEachIndexed { index, multiNode ->
@@ -587,17 +585,18 @@ internal object Devirtualization {
                 }
             }
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
                 topologicalOrder.forEachIndexed { index, multiNode ->
-                    println("Types of multi-node #$index")
+                    +"Types of multi-node #$index"
                     condensation.forEachNode(multiNode) { node ->
-                        println("    Node #${node.id}")
+                        +"    Node #${node.id}"
                         allTypes.asSequence()
                                 .withIndex()
                                 .filter { node.types[it.index] }.toList()
-                                .forEach { println("        ${it.value}") }
+                                .forEach { +"        ${it.value}" }
                     }
                 }
+                +""
             }
 
             val result = mutableMapOf<DataFlowIR.Node.VirtualCall, Pair<DevirtualizedCallSite, DataFlowIR.FunctionSymbol>>()
@@ -610,76 +609,66 @@ internal object Devirtualization {
                     val receiverNode = constraintGraph.virtualCallSiteReceivers[virtualCall]
                             ?: error("virtualCallSiteReceivers were not built for virtual call $virtualCall")
                     if (receiverNode.types[VIRTUAL_TYPE_ID]) {
-
+                        context.logMultiple {
-                        DEBUG_OUTPUT(0) {
+                            +"Unable to devirtualize callsite ${virtualCall.debugString()}"
-                            println("Unable to devirtualize callsite " +
+                            +"    receiver is Virtual"
-                                    (virtualCall.irCallSite?.let { ir2stringWhole(it) }
+                            logPathToType(reversedEdges, receiverNode, VIRTUAL_TYPE_ID)
-                                            ?: virtualCall.callee.toString()))
+                            +""
-                            println("    receiver is Virtual")
-                            printPathToType(reversedEdges, receiverNode, VIRTUAL_TYPE_ID)
                         }
-
                         return@forEachNonScopeNode
                     }
 
-                    DEBUG_OUTPUT(0) {
+                    context.log { "Devirtualized callsite ${virtualCall.debugString()}" }
-                        println("Devirtualized callsite " +
-                                (virtualCall.irCallSite?.let { ir2stringWhole(it) } ?: virtualCall.callee.toString()))
-                    }
-
                     val receiverType = virtualCall.receiverType.resolved()
                     val possibleReceivers = mutableListOf<DataFlowIR.Type.Declared>()
                     forEachBitInBoth(receiverNode.types, typeHierarchy.inheritorsOf(receiverType)) {
                         val type = allTypes[it]
                         assert(instantiatingClasses[it]) { "Non-instantiating class $type" }
                         if (type != nothing) {
-
+                            context.logMultiple {
-                            DEBUG_OUTPUT(0) {
+                                +"Path to type $type"
-                                println("Path to type $type")
+                                logPathToType(reversedEdges, receiverNode, it)
-                                printPathToType(reversedEdges, receiverNode, it)
                             }
-
                             possibleReceivers.add(type)
                         }
                     }
+                    context.log { "" }
 
                     result[virtualCall] = DevirtualizedCallSite(virtualCall.callee.resolved(),
                             possibleReceivers.map { possibleReceiverType ->
                                 val callee = possibleReceiverType.calleeAt(virtualCall)
                                 if (callee is DataFlowIR.FunctionSymbol.Declared && callee.symbolTableIndex < 0)
                                     error("Function ${possibleReceiverType}.$callee cannot be called virtually," +
-                                            " but actually is at call site: " +
+                                            " but actually is at call site: ${virtualCall.debugString()}")
-                                            (virtualCall.irCallSite?.let { ir2stringWhole(it) }
-                                                    ?: virtualCall.toString()))
                                 DevirtualizedCallee(possibleReceiverType, callee)
                             }) to function.symbol
 
                 }
             }
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("Devirtualized from current module:")
+                +"Devirtualized from current module:"
                 result.forEach { virtualCall, devirtualizedCallSite ->
                     if (virtualCall.irCallSite != null) {
-                        println("DEVIRTUALIZED")
+                        +"DEVIRTUALIZED"
-                        println("FUNCTION: ${devirtualizedCallSite.second}")
+                        +"FUNCTION: ${devirtualizedCallSite.second}"
-                        println("CALL SITE: ${virtualCall.irCallSite?.let { ir2stringWhole(it) } ?: virtualCall.toString()}")
+                        +"CALL SITE: ${virtualCall.debugString()}"
-                        println("POSSIBLE RECEIVERS:")
+                        +"POSSIBLE RECEIVERS:"
-                        devirtualizedCallSite.first.possibleCallees.forEach { println("    TYPE: ${it.receiverType}") }
+                        devirtualizedCallSite.first.possibleCallees.forEach { +"    TYPE: ${it.receiverType}" }
-                        devirtualizedCallSite.first.possibleCallees.forEach { println("    FUN: ${it.callee}") }
+                        devirtualizedCallSite.first.possibleCallees.forEach { +"    FUN: ${it.callee}" }
-                        println()
+                        +""
                     }
                 }
-                println("Devirtualized from external modules:")
+                +"Devirtualized from external modules:"
                 result.forEach { virtualCall, devirtualizedCallSite ->
                     if (virtualCall.irCallSite == null) {
-                        println("DEVIRTUALIZED")
+                        +"DEVIRTUALIZED"
-                        println("FUNCTION: ${devirtualizedCallSite.second}")
+                        +"FUNCTION: ${devirtualizedCallSite.second}"
-                        println("CALL SITE: ${virtualCall.irCallSite?.let { ir2stringWhole(it) } ?: virtualCall.toString()}")
+                        +"CALL SITE: ${virtualCall.debugString()}"
-                        println("POSSIBLE RECEIVERS:")
+                        +"POSSIBLE RECEIVERS:"
-                        devirtualizedCallSite.first.possibleCallees.forEach { println("    TYPE: ${it.receiverType}") }
+                        devirtualizedCallSite.first.possibleCallees.forEach { +"    TYPE: ${it.receiverType}" }
-                        devirtualizedCallSite.first.possibleCallees.forEach { println("    FUN: ${it.callee}") }
+                        devirtualizedCallSite.first.possibleCallees.forEach { +"    FUN: ${it.callee}" }
-                        println()
+                        +""
                     }
                 }
             }
@@ -915,18 +904,17 @@ internal object Devirtualization {
                     addEdge(functionNodesMap[body.returns]!!, functionConstraintGraph.returns)
                     addEdge(functionNodesMap[body.throws]!!, functionConstraintGraph.throws)
 
-                    DEBUG_OUTPUT(0) {
+                    context.logMultiple {
-                        println("CONSTRAINT GRAPH FOR $symbol")
+                        +"CONSTRAINT GRAPH FOR $symbol"
                         val ids = function.body.allScopes.flatMap { it.nodes }.withIndex().associateBy({ it.value }, { it.index })
                         function.body.forEachNonScopeNode { node ->
-                            println("FT NODE #${ids[node]}")
+                            +"FT NODE #${ids[node]}"
-                            DataFlowIR.Function.printNode(node, ids)
+                            +DataFlowIR.Function.nodeToString(node, ids)
                             val constraintNode = functionNodesMap[node] ?: variables[node] ?: return@forEachNonScopeNode
-                            println("       CG NODE #${constraintNode.id}: ${constraintNode.toString(allTypes)}")
+                            +"       CG NODE #${constraintNode.id}: ${constraintNode.toString(allTypes)}"
-                            println()
                         }
-                        println("Returns: #${ids[function.body.returns]}")
+                        +"Returns: #${ids[function.body.returns]}"
-                        println()
+                        +""
                     }
                 }
 
@@ -982,21 +970,17 @@ internal object Devirtualization {
             private fun addInstantiatingClass(type: DataFlowIR.Type.Declared) {
                 if (instantiatingClasses[type.index]) return
                 instantiatingClasses.set(type.index)
-
+                context.log { "Adding instantiating class: $type" }
-                DEBUG_OUTPUT(1) { println("Adding instantiating class: $type") }
-
                 checkSupertypes(type, type, BitSet())
             }
 
             private fun processVirtualCall(virtualCall: ConstraintGraphVirtualCall,
                                            receiverType: DataFlowIR.Type.Declared) {
-                DEBUG_OUTPUT(1) {
+                context.logMultiple {
-                    println("Processing virtual call: ${virtualCall.virtualCall.callee}")
+                    +"Processing virtual call: ${virtualCall.virtualCall.callee}"
-                    println("Receiver type: $receiverType")
+                    +"Receiver type: $receiverType"
                 }
-
                 val callee = receiverType.calleeAt(virtualCall.virtualCall)
-
                 addEdge(doCall(virtualCall.caller, callee, virtualCall.arguments,
                         callee.returnParameter.type.resolved()), virtualCall.returnsNode)
             }
@@ -1006,18 +990,17 @@ internal object Devirtualization {
                                         seenTypes: BitSet) {
                 seenTypes.set(type.index)
 
-                DEBUG_OUTPUT(1) {
+                context.logMultiple {
-                    println("Checking supertype $type of $inheritor")
+                    +"Checking supertype $type of $inheritor"
                     typesVirtualCallSites[type.index].let {
                         if (it.isEmpty())
-                            println("None virtual call sites encountered yet")
+                            +"None virtual call sites encountered yet"
                         else {
-                            println("Virtual call sites:")
+                            +"Virtual call sites:"
-                            it.forEach {
+                            it.forEach { +"    ${it.virtualCall.callee}" }
-                                println("    ${it.virtualCall.callee}")
-                            }
                         }
                     }
+                    +""
                 }
 
                 typesVirtualCallSites[type.index].let { virtualCallSites ->
@@ -1175,19 +1158,17 @@ internal object Devirtualization {
                             val callee = node.callee
                             val receiverType = node.receiverType.resolved()
 
-                            DEBUG_OUTPUT(0) {
+                            context.logMultiple {
-                                println("Virtual call")
+                                +"Virtual call"
-                                println("Caller: ${function.symbol}")
+                                +"Caller: ${function.symbol}"
-                                println("Callee: $callee")
+                                +"Callee: $callee"
-                                println("Receiver type: $receiverType")
+                                +"Receiver type: $receiverType"
-                            }
 
-                            DEBUG_OUTPUT(0) {
+                                +"Possible callees:"
-                                println("Possible callees:")
                                 forEachBitInBoth(typeHierarchy.inheritorsOf(receiverType), instantiatingClasses) {
-                                    println(allTypes[it].calleeAt(node))
+                                    +allTypes[it].calleeAt(node).toString()
                                 }
-                                println()
+                                +""
                             }
 
                             val returnType = node.returnType.resolved()

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/EscapeAnalysis.kt

@@ -13,6 +13,7 @@ import org.jetbrains.kotlin.backend.konan.DirectedGraphMultiNode
 import org.jetbrains.kotlin.backend.konan.llvm.Lifetime
 import org.jetbrains.kotlin.ir.IrElement
 import org.jetbrains.kotlin.backend.konan.Context
+import org.jetbrains.kotlin.backend.konan.logMultiple
 import org.jetbrains.kotlin.ir.declarations.IrClass
 import kotlin.math.min
 
@@ -104,12 +105,6 @@ internal object EscapeAnalysis {
      *     seeing all edges directed.
      */
 
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     // A special marker field for external types implemented in the runtime (mainly, arrays).
     // The types being passed to the constructor are not used in the analysis - just put there anything.
     private val intestinesField = DataFlowIR.Field(null, DataFlowIR.Type.Virtual, 1L, "inte\$tines")
@@ -317,16 +312,14 @@ internal object EscapeAnalysis {
                 return true
             }
 
-            override fun toString() = debugOutput(null)
+            override fun toString() = debugString(null)
 
-            fun debugOutput(root: String?): String {
+            fun debugString(root: String?) = buildString {
-                val result = StringBuilder()
+                append(root ?: kind.toString())
-                result.append(root ?: kind.toString())
                 path.forEach {
-                    result.append('.')
+                    append('.')
-                    result.append(it.name ?: "<no_name@${it.hash}>")
+                    append(it.name ?: "<no_name@${it.hash}>")
                 }
-                return result.toString()
             }
 
             fun goto(field: DataFlowIR.Field?) = when (field) {
@@ -447,7 +440,7 @@ internal object EscapeAnalysis {
     }
 
     private class InterproceduralAnalysis(
-            context: Context,
+            val context: Context,
             val callGraph: CallGraph,
             val intraproceduralAnalysisResults: Map<DataFlowIR.FunctionSymbol, FunctionAnalysisResult>,
             val externalModulesDFG: ExternalModulesDFG,
@@ -466,48 +459,44 @@ internal object EscapeAnalysis {
         val escapeAnalysisResults = mutableMapOf<DataFlowIR.FunctionSymbol.Declared, FunctionEscapeAnalysisResult>()
 
         fun analyze() {
-
+            context.logMultiple {
-            DEBUG_OUTPUT(0) {
+                +"CALL GRAPH"
-                println("CALL GRAPH")
+                callGraph.directEdges.forEach { (t, u) ->
-                callGraph.directEdges.forEach { t, u ->
+                    +"    FUN $t"
-                    println("    FUN $t")
                     u.callSites.forEach {
                         val label = when {
                             it.isVirtual -> "VIRTUAL"
                             callGraph.directEdges.containsKey(it.actualCallee) -> "LOCAL"
                             else -> "EXTERNAL"
                         }
-                        println("        CALLS $label ${it.actualCallee}")
+                        +"        CALLS $label ${it.actualCallee}"
-                    }
-                    callGraph.reversedEdges[t]!!.forEach {
-                        println("        CALLED BY $it")
                     }
+                    callGraph.reversedEdges[t]!!.forEach { +"        CALLED BY $it" }
                 }
+                +""
             }
 
             val condensation = DirectedGraphCondensationBuilder(callGraph).build()
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("CONDENSATION")
+                +"CONDENSATION"
                 condensation.topologicalOrder.forEach { multiNode ->
-                    println("    MULTI-NODE")
+                    +"    MULTI-NODE"
-                    multiNode.nodes.forEach {
+                    multiNode.nodes.forEach { +"        $it" }
-                        println("        $it")
-                    }
                 }
-                println("CONDENSATION(DETAILED)")
+                +""
+                +"CONDENSATION(DETAILED)"
                 condensation.topologicalOrder.forEach { multiNode ->
-                    println("    MULTI-NODE")
+                    +"    MULTI-NODE"
                     multiNode.nodes.forEach {
-                        println("        $it")
+                        +"        $it"
                         callGraph.directEdges[it]!!.callSites
                                 .filter { callGraph.directEdges.containsKey(it.actualCallee) }
-                                .forEach { println("            CALLS ${it.actualCallee}") }
+                                .forEach { +"            CALLS ${it.actualCallee}" }
-                        callGraph.reversedEdges[it]!!.forEach {
+                        callGraph.reversedEdges[it]!!.forEach { +"            CALLED BY $it" }
-                            println("            CALLED BY $it")
-                        }
                     }
                 }
+                +""
             }
 
             for (functionSymbol in callGraph.directEdges.keys) {
@@ -519,9 +508,9 @@ internal object EscapeAnalysis {
             for (multiNode in condensation.topologicalOrder.reversed())
                 analyze(callGraph, multiNode)
 
-            DEBUG_OUTPUT(1) {
+            context.logMultiple {
-                println("Managed to alloc on stack: ${stackAllocsCount * 100.0 / (globalAllocsCount + stackAllocsCount)}%")
+                +"Managed to alloc on stack: ${stackAllocsCount * 100.0 / (globalAllocsCount + stackAllocsCount)}%"
-                println("Total graph size: $totalGraphSize")
+                +"Total graph size: $totalGraphSize"
             }
         }
 
@@ -532,15 +521,15 @@ internal object EscapeAnalysis {
         private fun analyze(callGraph: CallGraph, multiNode: DirectedGraphMultiNode<DataFlowIR.FunctionSymbol.Declared>) {
             val nodes = multiNode.nodes.filter { intraproceduralAnalysisResults.containsKey(it) }.toMutableSet()
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("Analyzing multiNode:\n    ${nodes.joinToString("\n   ") { it.toString() }}")
+                +"Analyzing multiNode:\n    ${nodes.joinToString("\n   ") { it.toString() }}"
                 nodes.forEach { from ->
-                    println("DataFlowIR")
+                    +"DataFlowIR"
                     intraproceduralAnalysisResults[from]!!.function.debugOutput()
                     callGraph.directEdges[from]!!.callSites.forEach { to ->
-                        println("CALL")
+                        +"CALL"
-                        println("   from $from")
+                        +"   from $from"
-                        println("   to ${to.actualCallee}")
+                        +"   to ${to.actualCallee}"
                     }
                 }
             }
@@ -553,30 +542,23 @@ internal object EscapeAnalysis {
                 val function = toAnalyze.first()
                 toAnalyze.remove(function)
                 numberOfRuns[function] = numberOfRuns[function]!! + 1
-
+                context.log { "Processing function $function" }
-                DEBUG_OUTPUT(0) { println("Processing function $function") }
 
                 val startResult = escapeAnalysisResults[function]!!
-
+                context.log { "Start escape analysis result:\n$startResult" }
-                DEBUG_OUTPUT(0) { println("Start escape analysis result:\n$startResult") }
 
                 analyze(callGraph, pointsToGraphs[function]!!, function)
                 val endResult = escapeAnalysisResults[function]!!
+
                 if (startResult == endResult) {
-
+                    context.log { "Escape analysis is not changed" }
-                    DEBUG_OUTPUT(0) { println("Escape analysis is not changed") }
-
                 } else {
-
+                    context.log { "Escape analysis was refined:\n$endResult" }
-                    DEBUG_OUTPUT(0) { println("Escape analysis was refined:\n$endResult") }
-
                     if (numberOfRuns[function]!! > 1) {
-
+                        context.log {
-                        DEBUG_OUTPUT(0) {
+                            "WARNING: Escape analysis for $function seems not to be converging." +
-                            println("WARNING: Escape analysis for $function seems not to be converging." +
+                                    " Assuming conservative results."
-                                    " Assuming conservative results.")
                         }
-
                         escapeAnalysisResults[function] = FunctionEscapeAnalysisResult.pessimistic(function.parameters.size)
                         nodes.remove(function)
                     }
@@ -632,11 +614,9 @@ internal object EscapeAnalysis {
                 pointerSize /* typeinfo */ + 4 /* size */ + itemSize * length
 
         private fun analyze(callGraph: CallGraph, pointsToGraph: PointsToGraph, function: DataFlowIR.FunctionSymbol.Declared) {
-            DEBUG_OUTPUT(0) {
+            context.log {"Before calls analysis" }
-                println("Before calls analysis")
+            pointsToGraph.log()
-                pointsToGraph.print()
+            pointsToGraph.logDigraph(false)
-                pointsToGraph.printDigraph(false)
-            }
 
             callGraph.directEdges[function]!!.callSites.forEach {
                 val callee = it.actualCallee
@@ -648,20 +628,16 @@ internal object EscapeAnalysis {
                 pointsToGraph.processCall(it, calleeEAResult)
             }
 
-            DEBUG_OUTPUT(0) {
+            context.log { "After calls analysis" }
-                println("After calls analysis")
+            pointsToGraph.log()
-                pointsToGraph.print()
+            pointsToGraph.logDigraph(false)
-                pointsToGraph.printDigraph(false)
-            }
 
             // Build transitive closure.
             val eaResult = pointsToGraph.buildClosure()
 
-            DEBUG_OUTPUT(0) {
+            context.log { "After closure building" }
-                println("After closure building")
+            pointsToGraph.log()
-                pointsToGraph.print()
+            pointsToGraph.logDigraph(true)
-                pointsToGraph.printDigraph(true)
-            }
 
             escapeAnalysisResults[function] = eaResult
 
@@ -678,38 +654,29 @@ internal object EscapeAnalysis {
             val callee = callSite.actualCallee.resolved()
 
             val calleeEAResult = if (callSite.isVirtual) {
-
+                context.log { "A virtual call: $callee" }
-                DEBUG_OUTPUT(0) { println("A virtual call: $callee") }
-
                 FunctionEscapeAnalysisResult.pessimistic(callee.parameters.size)
             } else {
-
+                context.log { "An external call: $callee" }
-                DEBUG_OUTPUT(0) { println("An external call: $callee") }
-
                 if (callee.name?.startsWith("kfun:kotlin.") == true
                         // TODO: Is it possible to do it in a more fine-grained fashion?
                         && !callee.name.startsWith("kfun:kotlin.native.concurrent")) {
-
+                    context.log { "A function from K/N runtime - can use annotations" }
-                    DEBUG_OUTPUT(0) { println("A function from K/N runtime - can use annotations") }
-
                     FunctionEscapeAnalysisResult.fromBits(
                             callee.escapes ?: 0,
                             (0..callee.parameters.size).map { callee.pointsTo?.elementAtOrNull(it) ?: 0 }
                     )
                 } else {
-
+                    context.log { "An unknown function - assume pessimistic result" }
-                    DEBUG_OUTPUT(0) { println("An unknown function - assume pessimistic result") }
-
                     FunctionEscapeAnalysisResult.pessimistic(callee.parameters.size)
                 }
             }
 
-            DEBUG_OUTPUT(0) {
+            context.logMultiple {
-                println("Escape analysis result")
+                +"Escape analysis result"
-                println(calleeEAResult.toString())
+                +calleeEAResult.toString()
-                println()
+                +""
             }
-
             return calleeEAResult
         }
 
@@ -806,12 +773,11 @@ internal object EscapeAnalysis {
 
             fun escapes(node: PointsToGraphNode) = node in reachableFromEscapeOrigins || node in referencingEscapeOrigins
 
-            val ids = if (DEBUG > 0)
+            val ids = (
-                (listOf(functionAnalysisResult.function.body.rootScope)
+                    listOf(functionAnalysisResult.function.body.rootScope)
-                        + functionAnalysisResult.function.body.allScopes.flatMap { it.nodes }
+                            + functionAnalysisResult.function.body.allScopes.flatMap { it.nodes }
-                        )
+                    )
-                        .withIndex().associateBy({ it.value }, { it.index })
+                    .withIndex().associateBy({ it.value }, { it.index })
-            else null
 
             fun lifetimeOf(node: DataFlowIR.Node) = nodes[node]!!.let { it.forcedLifetime ?: lifetimeOf(it) }
 
@@ -846,16 +812,12 @@ internal object EscapeAnalysis {
             private val returnValues: Set<DataFlowIR.Node>
 
             init {
-
+                context.logMultiple {
-                DEBUG_OUTPUT(0) {
+                    +"Building points-to graph for function $functionSymbol"
-                    println("Building points-to graph for function $functionSymbol")
+                    +"Results of preliminary function analysis"
-                    println("Results of preliminary function analysis")
                 }
-
                 functionAnalysisResult.nodesRoles.forEach { (node, roles) ->
-
+                    context.log { "NODE ${nodeToString(node)}: $roles" }
-                    DEBUG_OUTPUT(0) { println("NODE ${nodeToString(node)}: $roles") }
-
                     nodes[node] = newNode(roles, node)
                 }
 
@@ -904,13 +866,13 @@ internal object EscapeAnalysis {
                 }
             }
 
-            private fun nodeToStringWhole(node: DataFlowIR.Node) = DataFlowIR.Function.nodeToString(node, ids!!)
+            private fun nodeToStringWhole(node: DataFlowIR.Node) = DataFlowIR.Function.nodeToString(node, ids)
 
-            private fun nodeToString(node: DataFlowIR.Node) = ids!![node].toString()
+            private fun nodeToString(node: DataFlowIR.Node) = ids[node].toString()
 
-            fun print() {
+            fun log() = context.logMultiple {
-                println("POINTS-TO GRAPH")
+                +"POINTS-TO GRAPH"
-                println("NODES")
+                +"NODES"
                 val tempIds = mutableMapOf<PointsToGraphNode, Int>()
                 var tempIndex = 0
                 allNodes.forEach {
@@ -919,18 +881,17 @@ internal object EscapeAnalysis {
                 }
                 allNodes.forEach {
                     val tempId = tempIds[it]
-                    println("    ${lifetimeOf(it)} ${it.depth} ${if (it in escapeOrigins) "ESCAPES" else ""} ${it.node?.let { nodeToString(it) } ?: "t$tempId"}")
+                    +"    ${lifetimeOf(it)} ${it.depth} ${if (it in escapeOrigins) "ESCAPES" else ""} ${it.node?.let { nodeToString(it) } ?: "t$tempId"}"
-                    print(it.node?.let { nodeToStringWhole(it) } ?: "        t$tempId\n")
+                    +(it.node?.let { nodeToStringWhole(it) } ?: "        t$tempId")
                 }
             }
 
-            fun printDigraph(
+            fun logDigraph(
                     markDrains: Boolean,
                     nodeFilter: (PointsToGraphNode) -> Boolean = { true },
                     nodeLabel: ((PointsToGraphNode) -> String)? = null
-            ) {
+            ) = context.logMultiple {
-                println("digraph {")
+                +"digraph {"
-                val ids = ids!!
                 val tempIds = mutableMapOf<PointsToGraphNode, Int>()
                 var tempIndex = 0
                 allNodes.forEach {
@@ -951,24 +912,23 @@ internal object EscapeAnalysis {
                         if (!nodeFilter(to)) continue
                         when (it) {
                             is PointsToGraphEdge.Assignment ->
-                                println("    \"${from.format()}\" -> \"${to.format()}\";")
+                                +"    \"${from.format()}\" -> \"${to.format()}\";"
                             is PointsToGraphEdge.Field ->
-                                println("    \"${from.format()}\" -> \"${to.format()}\" [ label=\"${it.field.name}\"];")
+                                +"    \"${from.format()}\" -> \"${to.format()}\" [ label=\"${it.field.name}\"];"
                         }
                     }
                 }
-                println("}")
+                +"}"
             }
 
             fun processCall(callSite: CallGraphNode.CallSite, calleeEscapeAnalysisResult: FunctionEscapeAnalysisResult) {
                 val call = callSite.call
-
+                context.logMultiple {
-                DEBUG_OUTPUT(0) {
+                    +"Processing callSite"
-                    println("Processing callSite")
+                    +nodeToStringWhole(call)
-                    println(nodeToStringWhole(call))
+                    +"Actual callee: ${callSite.actualCallee}"
-                    println("Actual callee: ${callSite.actualCallee}")
+                    +"Callee escape analysis result:"
-                    println("Callee escape analysis result:")
+                    +calleeEscapeAnalysisResult.toString()
-                    println(calleeEscapeAnalysisResult.toString())
                 }
 
                 val arguments = if (call is DataFlowIR.Node.NewObject) {
@@ -1009,56 +969,44 @@ internal object EscapeAnalysis {
                 calleeEscapeAnalysisResult.escapes.forEach { escapingNode ->
                     val (arg, node) = mapNode(escapingNode)
                     if (node == null) {
-
+                        context.log { "WARNING: There is no node ${nodeToString(arg!!)}" }
-                        DEBUG_OUTPUT(0) { println("WARNING: There is no node ${nodeToString(arg!!)}") }
-
                         return@forEach
                     }
                     escapeOrigins += node
-
+                    context.log { "Node ${escapingNode.debugString(arg?.let { nodeToString(it) })} escapes" }
-                    DEBUG_OUTPUT(0) {
-                        println("Node ${escapingNode.debugOutput(arg?.let { nodeToString(it) })} escapes")
-                    }
                 }
 
                 calleeEscapeAnalysisResult.pointsTo.edges.forEach { edge ->
                     val (fromArg, fromNode) = mapNode(edge.from)
                     if (fromNode == null) {
-
+                        context.log { "WARNING: There is no node ${nodeToString(fromArg!!)}" }
-                        DEBUG_OUTPUT(0) { println("WARNING: There is no node ${nodeToString(fromArg!!)}") }
-
                         return@forEach
                     }
                     val (toArg, toNode) = mapNode(edge.to)
                     if (toNode == null) {
-
+                        context.log { "WARNING: There is no node ${nodeToString(toArg!!)}" }
-                        DEBUG_OUTPUT(0) { println("WARNING: There is no node ${nodeToString(toArg!!)}") }
-
                         return@forEach
                     }
                     fromNode.addAssignmentEdge(toNode)
 
-                    DEBUG_OUTPUT(0) {
+                    context.logMultiple {
-                        println("Adding edge")
+                        +"Adding edge"
-                        println("    FROM ${edge.from.debugOutput(fromArg?.let { nodeToString(it) })}")
+                        +"    FROM ${edge.from.debugString(fromArg?.let { nodeToString(it) })}"
-                        println("    TO ${edge.to.debugOutput(toArg?.let { nodeToString(it) })}")
+                        +"    TO ${edge.to.debugString(toArg?.let { nodeToString(it) })}"
                     }
                 }
             }
 
             fun buildClosure(): FunctionEscapeAnalysisResult {
-
+                context.logMultiple {
-                DEBUG_OUTPUT(0) {
+                    +"BUILDING CLOSURE"
-                    println("BUILDING CLOSURE")
+                    +"Return values:"
-                    println("Return values:")
+                    returnValues.forEach { +"    ${nodeToString(it)}" }
-                    returnValues.forEach {
-                        println("    ${nodeToString(it)}")
-                    }
                 }
 
                 buildDrains()
 
-                DEBUG_OUTPUT(0) { printDigraph(true) }
+                logDigraph(true)
 
                 computeLifetimes()
 
@@ -1072,9 +1020,7 @@ internal object EscapeAnalysis {
                  */
                 val (numberOfDrains, nodeIds) = paintInterestingNodes()
 
-                DEBUG_OUTPUT(0) {
+                logDigraph(true, { nodeIds[it] != null }, { nodeIds[it].toString() })
-                    printDigraph(true, { nodeIds[it] != null }, { nodeIds[it].toString() })
-                }
 
                 // TODO: Remove redundant edges.
                 val compressedEdges = mutableListOf<CompressedPointsToGraph.Edge>()
@@ -1616,11 +1562,7 @@ internal object EscapeAnalysis {
 
                     if (lifetime != computedLifetime) {
                         if (propagateExiledToHeapObjects && node.isAlloc) {
-
+                            context.log { "Forcing node ${nodeToString(node)} to escape" }
-                            DEBUG_OUTPUT(0) {
-                                println("Forcing node ${nodeToString(node)} to escape")
-                            }
-
                             escapeOrigins += ptgNode
                             propagateEscapeOrigin(ptgNode)
                         } else {
@@ -1640,11 +1582,7 @@ internal object EscapeAnalysis {
                         allowedToAlloc = 0
                         // Do not exile primitive arrays - they ain't reference no object.
                         if (irClass.symbol == symbols.array && propagateExiledToHeapObjects) {
-
+                            context.log { "Forcing node ${nodeToString(ptgNode.node!!)} to escape" }
-                            DEBUG_OUTPUT(0) {
-                                println("Forcing node ${nodeToString(ptgNode.node!!)} to escape")
-                            }
-
                             escapeOrigins += ptgNode
                             propagateEscapeOrigin(ptgNode)
                         } else {

backend.native/compiler/ir/backend.native/src/org/jetbrains/kotlin/backend/konan/optimizations/LocalEscapeAnalysis.kt

@@ -8,15 +8,10 @@ package org.jetbrains.kotlin.backend.konan.optimizations
 import org.jetbrains.kotlin.backend.konan.llvm.Lifetime
 import org.jetbrains.kotlin.ir.IrElement
 import org.jetbrains.kotlin.backend.konan.Context
+import org.jetbrains.kotlin.backend.konan.logMultiple
 import org.jetbrains.kotlin.backend.konan.descriptors.isArrayWithFixedSizeItems
 
 internal object LocalEscapeAnalysis {
-    private val DEBUG = 0
-
-    private inline fun DEBUG_OUTPUT(severity: Int, block: () -> Unit) {
-        if (DEBUG > severity) block()
-    }
-
     private enum class EscapeState {
         GLOBAL_ESCAPE,       // escape through global reference
         ARG_ESCAPE,          // escapes through function arguments, return or throw
@@ -187,7 +182,7 @@ internal object LocalEscapeAnalysis {
                 }
                 ir?.let {
                     lifetimes.put(it, Lifetime.STACK)
-                    DEBUG_OUTPUT(3) { println("${ir} does not escape") }
+                    context.log { "$ir does not escape" }
                 }
             }
         }
@@ -195,18 +190,18 @@ internal object LocalEscapeAnalysis {
 
     fun analyze(context: Context, moduleDFG: ModuleDFG, lifetimes: MutableMap<IrElement, Lifetime>) {
         moduleDFG.functions.forEach { (name, function) ->
-            DEBUG_OUTPUT(5) {
+            context.logMultiple {
-                println("===============================================")
+                +"==============================================="
-                println("Visiting $name")
+                +"Visiting $name"
-                println("DATA FLOW IR:")
+                +"DATA FLOW IR:"
-                function.debugOutput()
+                +function.debugString()
             }
             FunctionAnalyzer(function, context).analyze(lifetimes)
         }
     }
 
     fun computeLifetimes(context: Context, moduleDFG: ModuleDFG, lifetimes: MutableMap<IrElement, Lifetime>) {
-        DEBUG_OUTPUT(1) { println("In local EA") }
+        context.log { "In local EA" }
         assert(lifetimes.isEmpty())
         analyze(context, moduleDFG, lifetimes)
     }