Added extra logging in incremental cache and Kotlin Builder.

2015-06-18 22:42:00 +03:00
parent 5fabb962ae
commit 23eab73507
3 changed files with 102 additions and 66 deletions
@@ -16,27 +16,30 @@

 package org.jetbrains.kotlin.load.kotlin.incremental

-import org.jetbrains.kotlin.name.FqName
-import org.jetbrains.kotlin.descriptors.PackageFragmentDescriptor
-import org.jetbrains.kotlin.psi.JetFile
 import com.intellij.util.containers.MultiMap
-import java.util.HashMap
+import org.apache.log4j.Logger
 import org.jetbrains.kotlin.descriptors.ModuleDescriptor
+import org.jetbrains.kotlin.descriptors.PackageFragmentDescriptor
 import org.jetbrains.kotlin.descriptors.PackageFragmentProvider
 import org.jetbrains.kotlin.descriptors.impl.PackageFragmentDescriptorImpl
-import org.jetbrains.kotlin.resolve.scopes.JetScope
-import org.jetbrains.kotlin.storage.StorageManager
-import org.jetbrains.kotlin.serialization.deserialization.descriptors.DeserializedPackageMemberScope
-import org.jetbrains.kotlin.serialization.*
-import org.jetbrains.kotlin.serialization.jvm.*
-import org.jetbrains.kotlin.resolve.jvm.JavaDescriptorResolver
-import org.jetbrains.kotlin.utils.addToStdlib.singletonOrEmptyList
-import org.jetbrains.kotlin.storage.NotNullLazyValue
 import org.jetbrains.kotlin.load.kotlin.PackagePartClassUtils
-import org.jetbrains.kotlin.resolve.jvm.JvmClassName
 import org.jetbrains.kotlin.load.kotlin.incremental.cache.IncrementalCache
+import org.jetbrains.kotlin.name.FqName
 import org.jetbrains.kotlin.name.Name
+import org.jetbrains.kotlin.psi.JetFile
+import org.jetbrains.kotlin.resolve.jvm.JvmClassName
+import org.jetbrains.kotlin.resolve.scopes.JetScope
+import org.jetbrains.kotlin.serialization.PackageData
+import org.jetbrains.kotlin.serialization.ProtoBuf
 import org.jetbrains.kotlin.serialization.deserialization.DeserializationComponents
+import org.jetbrains.kotlin.serialization.deserialization.descriptors.DeserializedPackageMemberScope
+import org.jetbrains.kotlin.serialization.jvm.JvmProtoBuf
+import org.jetbrains.kotlin.serialization.jvm.JvmProtoBufUtil
+import org.jetbrains.kotlin.storage.NotNullLazyValue
+import org.jetbrains.kotlin.storage.StorageManager
+import org.jetbrains.kotlin.utils.addToStdlib.singletonOrEmptyList
+import java.util.HashMap
+import kotlin.reflect.jvm.java

 public class IncrementalPackageFragmentProvider(
        sourceFiles: Collection<JetFile>,
@@ -47,6 +50,10 @@ public class IncrementalPackageFragmentProvider(
        val moduleId: String
 ) : PackageFragmentProvider {

+    private companion object {
+        private val LOG = Logger.getLogger(IncrementalPackageFragmentProvider::class.java)
+    }
+
    val obsoletePackageParts = incrementalCache.getObsoletePackageParts().toSet()
    val fqNameToSubFqNames = MultiMap<FqName, FqName>()
    val fqNameToPackageFragment = HashMap<FqName, PackageFragmentDescriptor>()
@@ -110,18 +117,24 @@ public class IncrementalPackageFragmentProvider(
                { listOf() }
        ) {
            override fun filteredMemberProtos(allMemberProtos: Collection<ProtoBuf.Callable>): Collection<ProtoBuf.Callable> {
-                return allMemberProtos
-                        .filter {
-                            member ->
-                            if (member.hasExtension(JvmProtoBuf.implClassName)) {
-                                val shortName = packageData.getNameResolver().getName(member.getExtension(JvmProtoBuf.implClassName)!!)
-                                val internalName = JvmClassName.byFqNameWithoutInnerClasses(fqName.child(shortName)).getInternalName()
-                                internalName !in obsoletePackageParts
-                            }
-                            else {
-                                true
-                            }
-                        }
+                fun getPackagePart(callable: ProtoBuf.Callable) =
+                        callable.getExtension(JvmProtoBuf.implClassName)?.let { packageData.getNameResolver().getName(it) }
+
+                fun shouldSkipPackagePart(name: Name) =
+                        JvmClassName.byFqNameWithoutInnerClasses(fqName.child(name)).getInternalName() in obsoletePackageParts
+
+                if (LOG.isDebugEnabled()) {
+                    val allPackageParts = allMemberProtos
+                            .map (::getPackagePart)
+                            .filterNotNull()
+                            .toSet()
+                    val skippedPackageParts = allPackageParts.filter { shouldSkipPackagePart(it) }
+
+                    LOG.debug("Loading incremental package fragment for package '$fqName'," +
+                              " all package parts: $allPackageParts, skipped parts: $skippedPackageParts")
+                }
+
+                return allMemberProtos.filter { getPackagePart(it)?.let { !shouldSkipPackagePart(it) } ?: true }
            }
        }
    }
@@ -59,10 +59,7 @@ import org.jetbrains.kotlin.load.kotlin.header.isCompatiblePackageFacadeKind
 import org.jetbrains.kotlin.load.kotlin.incremental.cache.IncrementalCache
 import org.jetbrains.kotlin.load.kotlin.incremental.cache.IncrementalCacheProvider
 import org.jetbrains.kotlin.resolve.jvm.JvmClassName
-import org.jetbrains.kotlin.utils.LibraryUtils
-import org.jetbrains.kotlin.utils.PathUtil
-import org.jetbrains.kotlin.utils.keysToMap
-import org.jetbrains.kotlin.utils.sure
+import org.jetbrains.kotlin.utils.*
 import org.jetbrains.org.objectweb.asm.ClassReader
 import java.io.File
 import java.util.ArrayList
@@ -74,7 +71,7 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR
    companion object {
        public val KOTLIN_BUILDER_NAME: String = "Kotlin Builder"

-        private val LOG = Logger.getInstance("#org.jetbrains.jps.cmdline.BuildSession")
+        val LOG = Logger.getInstance("#org.jetbrains.kotlin.jps.build.KotlinBuilder")
    }

    private val statisticsLogger = TeamcityStatisticsLogger()
@@ -122,6 +119,7 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR
        val dataManager = context.getProjectDescriptor().dataManager

        if (chunk.getTargets().any { dataManager.getDataPaths().getKotlinCacheVersion(it).isIncompatible() }) {
+            LOG.info("Clearing caches for " + chunk.getTargets().map { it.getPresentableName() }.join())
            chunk.getTargets().forEach { dataManager.getKotlinCache(it).clean() }
            return CHUNK_REBUILD_REQUIRED
        }
@@ -160,6 +158,13 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR


        val compilationErrors = Utils.ERRORS_DETECTED_KEY[context, false]
+        if (compilationErrors) {
+            LOG.info("Compiled with errors")
+        }
+        else {
+            LOG.info("Compiled successfully")
+        }
+
        val generatedFiles = getGeneratedFiles(chunk, outputItemCollector)

        registerOutputItems(outputConsumer, generatedFiles)
@@ -218,6 +223,7 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR
            messageCollector: MessageCollectorAdapter, project: JpsProject
    ): OutputItemsCollectorImpl? {
        if (JpsUtils.isJsKotlinModule(chunk.representativeTarget())) {
+            LOG.debug("Compiling to JS ${filesToCompile.values().size()} files in " + filesToCompile.keySet().map { it.getPresentableName() }.join())
            return compileToJs(chunk, commonArguments, environment, messageCollector, project)
        }

@@ -261,6 +267,7 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR
                { className ->
                    className.startsWith("org.jetbrains.kotlin.load.kotlin.incremental.cache.")
                    || className == "org.jetbrains.kotlin.config.Services"
+                    || className.startsWith("org.apache.log4j.") // For logging from compiler
                },
                compilerServices
        )
@@ -468,17 +475,19 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR

        val processedTargetsWithRemoved = getProcessedTargetsWithRemovedFilesContainer(context)

-        var haveRemovedFiles = false
+        var totalRemovedFiles = 0
        for (target in chunk.getTargets()) {
-            if (!KotlinSourceFileCollector.getRemovedKotlinFiles(dirtyFilesHolder, target).isEmpty()) {
+            val removedFilesInTarget = KotlinSourceFileCollector.getRemovedKotlinFiles(dirtyFilesHolder, target)
+            if (!removedFilesInTarget.isEmpty()) {
                if (processedTargetsWithRemoved.add(target)) {
-                    haveRemovedFiles = true
+                    totalRemovedFiles += removedFilesInTarget.size()
                }
            }
        }

-        val moduleFile = KotlinBuilderModuleScriptGenerator.generateModuleDescription(context, chunk, filesToCompile, haveRemovedFiles)
+        val moduleFile = KotlinBuilderModuleScriptGenerator.generateModuleDescription(context, chunk, filesToCompile, totalRemovedFiles != 0)
        if (moduleFile == null) {
+            KotlinBuilder.LOG.debug("Not compiling, because no files affected: " + filesToCompile.keySet().map { it.getPresentableName() }.join())
            // No Kotlin sources found
            return null
        }
@@ -487,6 +496,10 @@ public class KotlinBuilder : ModuleLevelBuilder(BuilderCategory.SOURCE_PROCESSOR
        val k2JvmArguments = JpsKotlinCompilerSettings.getK2JvmCompilerArguments(project)
        val compilerSettings = JpsKotlinCompilerSettings.getCompilerSettings(project)

+        KotlinBuilder.LOG.debug("Compiling to JVM ${filesToCompile.values().size()} files"
+                        + (if (totalRemovedFiles == 0) "" else " ($totalRemovedFiles removed files)")
+                        + " in " + filesToCompile.keySet().map { it.getPresentableName() }.join())
+
        runK2JvmCompiler(commonArguments, k2JvmArguments, compilerSettings, messageCollector, environment, moduleFile, outputItemCollector)
        moduleFile.delete()

@@ -16,40 +16,36 @@

 package org.jetbrains.kotlin.jps.incremental

-import org.jetbrains.kotlin.jps.incremental.IncrementalCacheImpl.RecompilationDecision.*
-import java.io.File
-import com.intellij.util.io.PersistentHashMap
-import java.io.DataOutput
-import com.intellij.util.io.IOUtil
-import java.io.DataInput
-import org.jetbrains.kotlin.name.FqName
-import com.intellij.util.io.DataExternalizer
-import org.jetbrains.kotlin.serialization.jvm.BitEncoding
-import java.util.Arrays
-import org.jetbrains.org.objectweb.asm.*
-import com.intellij.util.io.EnumeratorStringDescriptor
-import org.jetbrains.kotlin.load.java.JvmAnnotationNames
-import org.jetbrains.kotlin.resolve.jvm.JvmClassName
-import org.jetbrains.kotlin.load.kotlin.incremental.cache.IncrementalCache
-import java.util.HashMap
-import org.jetbrains.kotlin.load.kotlin.PackageClassUtils
-import java.security.MessageDigest
-import org.jetbrains.jps.incremental.storage.StorageOwner
-import org.jetbrains.jps.builders.storage.StorageProvider
-import java.io.IOException
-import org.jetbrains.kotlin.load.java.JvmAbi
-import org.jetbrains.kotlin.load.kotlin.header.isCompatiblePackageFacadeKind
-import org.jetbrains.kotlin.load.kotlin.header.isCompatibleClassKind
-import org.jetbrains.jps.incremental.storage.BuildDataManager
+import com.intellij.util.io.*
+import org.jetbrains.annotations.TestOnly
 import org.jetbrains.jps.builders.BuildTarget
 import org.jetbrains.jps.builders.storage.BuildDataPaths
-import com.intellij.util.io.BooleanDataDescriptor
-import java.util.ArrayList
-import org.jetbrains.annotations.TestOnly
+import org.jetbrains.jps.builders.storage.StorageProvider
+import org.jetbrains.jps.incremental.storage.BuildDataManager
 import org.jetbrains.jps.incremental.storage.PathStringDescriptor
+import org.jetbrains.jps.incremental.storage.StorageOwner
 import org.jetbrains.kotlin.config.IncrementalCompilation
+import org.jetbrains.kotlin.jps.build.KotlinBuilder
+import org.jetbrains.kotlin.jps.incremental.IncrementalCacheImpl.RecompilationDecision.DO_NOTHING
+import org.jetbrains.kotlin.jps.incremental.IncrementalCacheImpl.RecompilationDecision.RECOMPILE_ALL_IN_CHUNK_AND_DEPENDANTS
+import org.jetbrains.kotlin.jps.incremental.IncrementalCacheImpl.RecompilationDecision.RECOMPILE_OTHER_IN_CHUNK_AND_DEPENDANTS
+import org.jetbrains.kotlin.jps.incremental.IncrementalCacheImpl.RecompilationDecision.RECOMPILE_OTHER_KOTLIN_IN_CHUNK
+import org.jetbrains.kotlin.load.java.JvmAbi
+import org.jetbrains.kotlin.load.java.JvmAnnotationNames
+import org.jetbrains.kotlin.load.kotlin.PackageClassUtils
+import org.jetbrains.kotlin.load.kotlin.header.isCompatibleClassKind
+import org.jetbrains.kotlin.load.kotlin.header.isCompatiblePackageFacadeKind
+import org.jetbrains.kotlin.load.kotlin.incremental.cache.IncrementalCache
+import org.jetbrains.kotlin.name.FqName
+import org.jetbrains.kotlin.resolve.jvm.JvmClassName
+import org.jetbrains.kotlin.serialization.jvm.BitEncoding
 import org.jetbrains.kotlin.utils.Printer
-import java.io.DataInputStream
+import org.jetbrains.org.objectweb.asm.*
+import java.io.*
+import java.security.MessageDigest
+import java.util.ArrayList
+import java.util.Arrays
+import java.util.HashMap

 val INLINE_ANNOTATION_DESC = "Lkotlin/inline;"

@@ -77,7 +73,11 @@ class CacheFormatVersion(targetDataRoot: File) {
        val versionNumber = file.readText().toInt()
        val expectedVersionNumber = actualCacheFormatVersion()

-        return versionNumber != expectedVersionNumber
+        if (versionNumber != expectedVersionNumber) {
+            KotlinBuilder.LOG.info("Incompatible incremental cache version, expected $expectedVersionNumber, actual $versionNumber")
+            return true
+        }
+        return false
    }

    fun saveIfNeeded() {
@@ -147,7 +147,7 @@ public class IncrementalCacheImpl(targetDataRoot: File) : StorageOwner, Incremen
        dirtyOutputClassesMap.notDirty(className.getInternalName())
        sourceFiles.forEach { sourceToClassesMap.addSourceToClass(it, className) }

-        return when {
+        val decision = when {
            header.isCompatiblePackageFacadeKind() ->
                getRecompilationDecision(
                        protoChanged = protoMap.put(className, BitEncoding.decodeBytes(header.annotationData)),
@@ -179,6 +179,10 @@ public class IncrementalCacheImpl(targetDataRoot: File) : StorageOwner, Incremen
                DO_NOTHING
            }
        }
+        if (decision != DO_NOTHING) {
+            KotlinBuilder.LOG.debug("$decision because $className is changed")
+        }
+        return decision
    }

    public fun clearCacheForRemovedClasses(): RecompilationDecision {
@@ -191,6 +195,9 @@ public class IncrementalCacheImpl(targetDataRoot: File) : StorageOwner, Incremen
                    constantsChanged = internalClassName in constantsMap,
                    inlinesChanged = internalClassName in inlineFunctionsMap
            )
+            if (newDecision != DO_NOTHING) {
+                KotlinBuilder.LOG.debug("$newDecision because $internalClassName is removed")
+            }

            recompilationDecision = recompilationDecision.merge(newDecision)

@@ -204,7 +211,10 @@ public class IncrementalCacheImpl(targetDataRoot: File) : StorageOwner, Incremen
    }

    public override fun getObsoletePackageParts(): Collection<String> {
-        return dirtyOutputClassesMap.getDirtyOutputClasses().filter { packagePartMap.isPackagePart(JvmClassName.byInternalName(it)) }
+        val obsoletePackageParts =
+                dirtyOutputClassesMap.getDirtyOutputClasses().filter { packagePartMap.isPackagePart(JvmClassName.byInternalName(it)) }
+        KotlinBuilder.LOG.debug("Obsolete package parts: ${obsoletePackageParts}")
+        return obsoletePackageParts
    }

    public override fun getPackageData(fqName: String): ByteArray? {