Add debug log for script dependencies loading process

idea/idea-core/src/org/jetbrains/kotlin/idea/core/script/dependencies/AsyncScriptDependenciesLoader.kt

@@ -74,6 +74,8 @@ class AsyncScriptDependenciesLoader internal constructor(project: Project) : Scr
 
     private fun runDependenciesUpdate(file: VirtualFile) {
         val scriptDef = runReadAction { file.findScriptDefinition(project) } ?: return
+
+        debug(file) { "start async dependencies loading" }
         // runBlocking is using there to avoid loading dependencies asynchronously
         // because it leads to starting more than one gradle daemon in case of resolving dependencies in build.gradle.kts
         // It is more efficient to use one hot daemon consistently than multiple daemon in parallel
@@ -84,6 +86,9 @@ class AsyncScriptDependenciesLoader internal constructor(project: Project) : Scr
                 t.asResolveFailure(scriptDef)
             }
         }
+
+        debug(file) { "finish async dependencies loading" }
+
         processResult(result, file, scriptDef)
     }
 
@@ -140,6 +145,8 @@ class AsyncScriptDependenciesLoader internal constructor(project: Project) : Scr
         fun addTask(file: VirtualFile) {
             if (sequenceOfFiles.contains(file)) return
 
+            debug(file) { "added to update queue" }
+
             sequenceOfFiles.add(file)
 
             // If the queue is longer than 3, show progress and cancel button

idea/idea-core/src/org/jetbrains/kotlin/idea/core/script/dependencies/FromFileAttributeScriptDependenciesLoader.kt

@@ -17,6 +17,7 @@ class FromFileAttributeScriptDependenciesLoader(project: Project) : ScriptDepend
 
     override fun loadDependencies(file: VirtualFile) {
         val deserializedDependencies = file.scriptDependencies ?: return
+        debug(file) { "dependencies from fileAttributes = $deserializedDependencies" }
         saveToCache(file, deserializedDependencies)
     }
 

idea/idea-core/src/org/jetbrains/kotlin/idea/core/script/dependencies/OutsiderFileDependenciesLoader.kt

@@ -18,7 +18,9 @@ class OutsiderFileDependenciesLoader(project: Project) : ScriptDependenciesLoade
 
     override fun loadDependencies(file: VirtualFile) {
         val fileOrigin = OutsidersPsiFileSupportUtils.getOutsiderFileOrigin(project, file) ?: return
-        saveToCache(file, ScriptDependenciesManager.getInstance(project).getScriptDependencies(fileOrigin))
+        val originDependencies = ScriptDependenciesManager.getInstance(project).getScriptDependencies(fileOrigin)
+        debug(file) { "dependencies for outsider file = $originDependencies" }
+        saveToCache(file, originDependencies)
     }
 
     override fun shouldShowNotification(): Boolean = false

idea/idea-core/src/org/jetbrains/kotlin/idea/core/script/dependencies/ScriptDependenciesLoader.kt

@@ -8,6 +8,7 @@ package org.jetbrains.kotlin.idea.core.script.dependencies
 import com.intellij.openapi.application.ApplicationManager
 import com.intellij.openapi.application.TransactionGuard
 import com.intellij.openapi.components.ServiceManager
+import com.intellij.openapi.diagnostic.Logger
 import com.intellij.openapi.project.Project
 import com.intellij.openapi.roots.ex.ProjectRootManagerEx
 import com.intellij.openapi.util.EmptyRunnable
@@ -48,6 +49,8 @@ abstract class ScriptDependenciesLoader(protected val project: Project) {
     private val reporter: ScriptReportSink = ServiceManager.getService(project, ScriptReportSink::class.java)
 
     protected fun processResult(result: DependenciesResolver.ResolveResult, file: VirtualFile, scriptDef: KotlinScriptDefinition) {
+        debug(file) { "dependencies from ${this.javaClass} received = $result" }
+
         if (cache[file] == null) {
             saveDependencies(result, file, scriptDef)
             attachReportsIfChanged(result, file, scriptDef)
@@ -57,12 +60,18 @@ abstract class ScriptDependenciesLoader(protected val project: Project) {
         val newDependencies = result.dependencies?.adjustByDefinition(scriptDef)
         if (cache[file] != newDependencies) {
             if (shouldShowNotification() && !ApplicationManager.getApplication().isUnitTestMode) {
+                debug(file) {
+                    "dependencies changed, notification was shown: old = ${cache[file]}, new = $newDependencies"
+                }
                 file.addScriptDependenciesNotificationPanel(result, project) {
                     saveDependencies(it, file, scriptDef)
                     attachReportsIfChanged(it, file, scriptDef)
                     submitMakeRootsChange()
                 }
             } else {
+                debug(file) {
+                    "dependencies changed, new dependencies were applied automatically: old = ${cache[file]}, new = $newDependencies"
+                }
                 saveDependencies(result, file, scriptDef)
                 attachReportsIfChanged(result, file, scriptDef)
             }
@@ -93,6 +102,9 @@ abstract class ScriptDependenciesLoader(protected val project: Project) {
     protected fun saveToCache(file: VirtualFile, dependencies: ScriptDependencies) {
         val rootsChanged = cache.hasNotCachedRoots(dependencies)
         if (cache.save(file, dependencies)) {
+            debug(file) {
+                "dependencies were saved to file attributes: dependencies = $dependencies"
+            }
             file.scriptDependencies = dependencies
         }
 
@@ -110,6 +122,8 @@ abstract class ScriptDependenciesLoader(protected val project: Project) {
             runWriteAction {
                 if (project.isDisposed) return@runWriteAction
 
+                debug(null) { "root change event for ${this.javaClass}" }
+
                 shouldNotifyRootsChanged = false
                 ProjectRootManagerEx.getInstanceEx(project)?.makeRootsChange(EmptyRunnable.getInstance(), false, true)
                 ScriptDependenciesModificationTracker.getInstance(project).incModificationCount()
@@ -124,4 +138,14 @@ abstract class ScriptDependenciesLoader(protected val project: Project) {
 
         return true
     }
+
+    companion object {
+        private val LOG = Logger.getInstance("#org.jetbrains.kotlin.idea.script")
+
+        internal fun debug(file: VirtualFile? = null, message: () -> String) {
+            if (LOG.isDebugEnabled) {
+                LOG.debug("[KOTLIN SCRIPT] " + (file?.let { "file = ${file.path}, " } ?: "") + message())
+            }
+        }
+    }
 }

idea/idea-core/src/org/jetbrains/kotlin/idea/core/script/dependencies/SyncScriptDependenciesLoader.kt

@@ -18,7 +18,9 @@ class SyncScriptDependenciesLoader internal constructor(project: Project) : Scri
 
     override fun loadDependencies(file: VirtualFile) {
         val scriptDef = file.findScriptDefinition(project) ?: return
+        debug(file) { "start sync dependencies loading" }
         val result = contentLoader.loadContentsAndResolveDependencies(scriptDef, file)
+        debug(file) { "finish sync dependencies loading" }
         processResult(result, file, scriptDef)
     }