[Daemon] Improve some daemon log messages

A few messages were improved:
  * If the daemon process died at the startup, add its last 10 lines of the output to the log and report to the EXCEPTION (ERROR in the case of Gradle) level
  * If some exception occurs during connection attempt, add its stacktrace and report to the EXCEPTION (ERROR in the case of Gradle) level
  * Added more DEBUG level messages
  * Some important messages are moved to the INFO level
  * Added a suggestion to report issue to kotl.in/issue
^KT-55322 Fixed
This commit is contained in:
Alexander.Likhachev
2023-11-21 12:58:05 +01:00
committed by Space Team
parent 95bc49054f
commit b000b66ef7
8 changed files with 120 additions and 27 deletions
@@ -95,7 +95,7 @@ object KotlinCompilerRunnerUtils {
if (connection == null || isDebugEnabled) { if (connection == null || isDebugEnabled) {
for (message in daemonReportMessages) { for (message in daemonReportMessages) {
val severity = when (message.category) { val severity = when (message.category) {
DaemonReportCategory.DEBUG -> CompilerMessageSeverity.INFO DaemonReportCategory.DEBUG -> CompilerMessageSeverity.LOGGING
DaemonReportCategory.INFO -> CompilerMessageSeverity.INFO DaemonReportCategory.INFO -> CompilerMessageSeverity.INFO
DaemonReportCategory.EXCEPTION -> CompilerMessageSeverity.EXCEPTION DaemonReportCategory.EXCEPTION -> CompilerMessageSeverity.EXCEPTION
} }
@@ -103,6 +103,7 @@ object KotlinCompilerClient {
sessionAliveFlagFile: File? = null, sessionAliveFlagFile: File? = null,
): CompileServiceSession? { ): CompileServiceSession? {
val ignoredDaemonSessionFiles = mutableSetOf<File>() val ignoredDaemonSessionFiles = mutableSetOf<File>()
var daemonStartupAttemptsCount = 0
return connectLoop(reportingTargets, autostart) { isLastAttempt -> return connectLoop(reportingTargets, autostart) { isLastAttempt ->
fun CompileService.tryToLeaseSession(): CompileServiceSession? { fun CompileService.tryToLeaseSession(): CompileServiceSession? {
@@ -112,8 +113,23 @@ object KotlinCompilerClient {
if (!leaseSession) return CompileServiceSession(this, CompileService.NO_SESSION) if (!leaseSession) return CompileServiceSession(this, CompileService.NO_SESSION)
return leaseCompileSession(sessionAliveFlagFile?.absolutePath).takeUnless { it is CompileService.CallResult.Dying }?.let { return when (val leaseSessionResult = leaseCompileSession(sessionAliveFlagFile?.absolutePath)) {
CompileServiceSession(this, it.get()) is CompileService.CallResult.Dying -> {
reportingTargets.report(DaemonReportCategory.DEBUG, "the daemon is already dying, skipping it")
null
}
is CompileService.CallResult.Good -> {
val sessionId = leaseSessionResult.get()
reportingTargets.report(DaemonReportCategory.DEBUG, "successfully leased a compile session (id = $sessionId)")
CompileServiceSession(this, sessionId)
}
else -> {
reportingTargets.report(DaemonReportCategory.DEBUG, "got an expected result on attempt to lease a compile session")
// the call to get() below shall lead to an exception throwing
// if it does happen, it indicates real problems,
// so no special handling is required, and it's ok to fail-fast
CompileServiceSession(this, leaseSessionResult.get())
}
} }
} }
@@ -133,8 +149,9 @@ object KotlinCompilerClient {
} }
is DaemonSearchResult.NotFound -> { is DaemonSearchResult.NotFound -> {
if (!isLastAttempt && autostart) { if (!isLastAttempt && autostart) {
if (startDaemon(compilerId, result.requiredJvmOptions, daemonOptions, reportingTargets)) { reportingTargets.report(DaemonReportCategory.DEBUG, "trying to start a new compiler daemon")
reportingTargets.report(DaemonReportCategory.DEBUG, "new daemon started, trying to find it") if (startDaemon(compilerId, result.requiredJvmOptions, daemonOptions, reportingTargets, daemonStartupAttemptsCount++)) {
reportingTargets.report(DaemonReportCategory.DEBUG, "new compiler daemon started, trying to find it")
} }
} }
null null
@@ -375,15 +392,17 @@ object KotlinCompilerClient {
if (res != null) return res if (res != null) return res
if (err != null) { val errorDetails = err?.let { ", error: ${it.stackTraceToString()}" } ?: ""
if (attempts >= DAEMON_CONNECT_CYCLE_ATTEMPTS || !autostart) {
reportingTargets.report( reportingTargets.report(
DaemonReportCategory.INFO, DaemonReportCategory.EXCEPTION,
(if (attempts >= DAEMON_CONNECT_CYCLE_ATTEMPTS || !autostart) "no more retries on: " else "retrying($attempts) on: ") "Failed connecting to the daemon in $attempts retries$errorDetails"
+ err.toString()
) )
} else {
reportingTargets.report(DaemonReportCategory.INFO, "#$attempts retrying connecting to the daemon $errorDetails")
} }
if (attempts++ > DAEMON_CONNECT_CYCLE_ATTEMPTS || !autostart) { if (++attempts > DAEMON_CONNECT_CYCLE_ATTEMPTS || !autostart) {
return null return null
} }
} }
@@ -436,6 +455,7 @@ object KotlinCompilerClient {
daemonJVMOptions: DaemonJVMOptions, daemonJVMOptions: DaemonJVMOptions,
daemonOptions: DaemonOptions, daemonOptions: DaemonOptions,
reportingTargets: DaemonReportingTargets, reportingTargets: DaemonReportingTargets,
startupAttempt: Int,
): Boolean { ): Boolean {
val javaExecutable = File(File(CompilerSystemProperties.JAVA_HOME.safeValue, "bin"), "java") val javaExecutable = File(File(CompilerSystemProperties.JAVA_HOME.safeValue, "bin"), "java")
val serverHostname = CompilerSystemProperties.JAVA_RMI_SERVER_HOSTNAME.value val serverHostname = CompilerSystemProperties.JAVA_RMI_SERVER_HOSTNAME.value
@@ -459,7 +479,7 @@ object KotlinCompilerClient {
COMPILER_DAEMON_CLASS_FQN + COMPILER_DAEMON_CLASS_FQN +
daemonOptions.mappers.flatMap { it.toArgs(COMPILE_DAEMON_CMDLINE_OPTIONS_PREFIX) } + daemonOptions.mappers.flatMap { it.toArgs(COMPILE_DAEMON_CMDLINE_OPTIONS_PREFIX) } +
compilerId.mappers.flatMap { it.toArgs(COMPILE_DAEMON_CMDLINE_OPTIONS_PREFIX) } compilerId.mappers.flatMap { it.toArgs(COMPILE_DAEMON_CMDLINE_OPTIONS_PREFIX) }
reportingTargets.report(DaemonReportCategory.DEBUG, "starting the daemon as: " + args.joinToString(" ")) reportingTargets.report(DaemonReportCategory.INFO, "starting the daemon as: " + args.joinToString(" "))
val processBuilder = ProcessBuilder(args) val processBuilder = ProcessBuilder(args)
processBuilder.redirectErrorStream(true) processBuilder.redirectErrorStream(true)
val workingDir = File(daemonOptions.runFilesPath).apply { mkdirs() } val workingDir = File(daemonOptions.runFilesPath).apply { mkdirs() }
@@ -470,6 +490,8 @@ object KotlinCompilerClient {
val isEchoRead = Semaphore(1) val isEchoRead = Semaphore(1)
isEchoRead.acquire() isEchoRead.acquire()
val lastDaemonCliOutputs = LastDaemonCliOutputs()
val stdoutThread = val stdoutThread =
thread { thread {
try { try {
@@ -477,6 +499,7 @@ object KotlinCompilerClient {
.reader() .reader()
.forEachLine { .forEachLine {
if (Thread.currentThread().isInterrupted) return@forEachLine if (Thread.currentThread().isInterrupted) return@forEachLine
lastDaemonCliOutputs.add(it)
if (it == COMPILE_DAEMON_IS_READY_MESSAGE) { if (it == COMPILE_DAEMON_IS_READY_MESSAGE) {
reportingTargets.report( reportingTargets.report(
DaemonReportCategory.DEBUG, DaemonReportCategory.DEBUG,
@@ -515,8 +538,8 @@ object KotlinCompilerClient {
return when { return when {
!isProcessAlive(daemon) -> { !isProcessAlive(daemon) -> {
reportingTargets.report( reportingTargets.report(
DaemonReportCategory.INFO, DaemonReportCategory.EXCEPTION,
"Daemon terminated unexpectedly with error code: ${daemon.exitValue()}" "The daemon has terminated unexpectedly on startup attempt #${startupAttempt + 1} with error code: ${daemon.exitValue()}. ${lastDaemonCliOutputs.getAsSingleString()}"
) )
false false
} }
@@ -0,0 +1,36 @@
/*
* Copyright 2010-2023 JetBrains s.r.o. and Kotlin Programming Language contributors.
* Use of this source code is governed by the Apache 2.0 license that can be found in the license/LICENSE.txt file.
*/
package org.jetbrains.kotlin.daemon.client
private const val limit = 10
private const val outputIndent = 4
/**
* Holds the last [limit] lines of the daemon process standard output to be able to print them in the case of problems with the daemon.
*/
internal class LastDaemonCliOutputs {
private val lastPrintedLines: MutableList<String> = LimitedLinkedList(limit)
private var totalCount = 0
fun add(line: String) {
lastPrintedLines.add(line)
totalCount++
}
private fun calculateAbsoluteIndex(relativeIndex: Int) = totalCount - lastPrintedLines.size + relativeIndex
private val ellipsisIfRequired
get() = if (totalCount > limit) " ".repeat(outputIndent) + "... (${totalCount - limit} more lines)${System.lineSeparator()}" else ""
fun getAsSingleString() = lastPrintedLines
.takeIf { it.isNotEmpty() }
?.withIndex()
?.joinToString(
System.lineSeparator(),
prefix = "The daemon process output:${System.lineSeparator()}$ellipsisIfRequired",
) { (index, line) -> " ".repeat(outputIndent) + "${calculateAbsoluteIndex(index) + 1}. $line" }
?: (" ".repeat(outputIndent) + "The daemon process produced no output")
}
@@ -0,0 +1,19 @@
/*
* Copyright 2010-2023 JetBrains s.r.o. and Kotlin Programming Language contributors.
* Use of this source code is governed by the Apache 2.0 license that can be found in the license/LICENSE.txt file.
*/
package org.jetbrains.kotlin.daemon.client
import java.util.*
internal class LimitedLinkedList<E>(private val limit: Int) : LinkedList<E>() {
override fun add(element: E): Boolean {
val added = super.add(element)
while (added && size > limit) {
super.remove()
}
return added
}
}
@@ -69,10 +69,6 @@ class ExecutionStrategyJvmIT : ExecutionStrategyIT() {
} }
abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() { abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() {
override val defaultBuildOptions: BuildOptions = super.defaultBuildOptions.copy(
logLevel = LogLevel.DEBUG
)
@DisplayName("Compilation via Kotlin daemon") @DisplayName("Compilation via Kotlin daemon")
@GradleTest @GradleTest
fun testDaemon(gradleVersion: GradleVersion) { fun testDaemon(gradleVersion: GradleVersion) {
@@ -113,7 +109,9 @@ abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() {
"build", "build",
"-Pkotlin.daemon.jvmargs=-Xmxqwerty", "-Pkotlin.daemon.jvmargs=-Xmxqwerty",
) { ) {
assertOutputContains("Failed to compile with Kotlin daemon. Fallback strategy (compiling without Kotlin daemon) is turned off.") assertOutputContains("Invalid maximum heap size: -Xmxqwerty")
assertOutputContains("Failed to compile with Kotlin daemon.")
assertOutputContains("Fallback strategy (compiling without Kotlin daemon) is turned off.")
} }
} }
} }
@@ -146,7 +144,9 @@ abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() {
"build", "build",
"-Pkotlin.daemon.jvmargs=-Xmxqwerty", "-Pkotlin.daemon.jvmargs=-Xmxqwerty",
) { ) {
assertOutputContains("Failed to compile with Kotlin daemon. Fallback strategy (compiling without Kotlin daemon) is turned off.") assertOutputContains("Invalid maximum heap size: -Xmxqwerty")
assertOutputContains("Failed to compile with Kotlin daemon.")
assertOutputContains("Fallback strategy (compiling without Kotlin daemon) is turned off.")
} }
} }
} }
@@ -212,7 +212,12 @@ abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() {
executionStrategy executionStrategy
} else { } else {
null null
} },
logLevel = if (!testFallbackStrategy && executionStrategy == KotlinCompilerExecutionStrategy.DAEMON) {
LogLevel.DEBUG // used daemon JVM options are reported only to the DEBUG logs
} else {
defaultBuildOptions.logLevel
},
) )
) { ) {
setupProject(this) setupProject(this)
@@ -232,6 +237,7 @@ abstract class ExecutionStrategyIT : KGPDaemonsBaseTest() {
assertNoBuildWarnings() assertNoBuildWarnings()
if (testFallbackStrategy) { if (testFallbackStrategy) {
assertOutputContains("Invalid maximum heap size: -Xmxqwerty")
assertOutputContains("Using fallback strategy: Compile without Kotlin daemon") assertOutputContains("Using fallback strategy: Compile without Kotlin daemon")
} else if (executionStrategy == KotlinCompilerExecutionStrategy.DAEMON) { } else if (executionStrategy == KotlinCompilerExecutionStrategy.DAEMON) {
// 256m is the default value for Gradle 5.0+ // 256m is the default value for Gradle 5.0+
@@ -158,9 +158,12 @@ fun BuildResult.assertOutputContainsExactlyTimes(
* Assert build contains no warnings. * Assert build contains no warnings.
*/ */
fun BuildResult.assertNoBuildWarnings( fun BuildResult.assertNoBuildWarnings(
expectedWarnings: Set<String> = emptySet(), additionalExpectedWarnings: Set<String> = emptySet(),
) { ) {
val cleanedOutput = expectedWarnings.fold(output) { acc, s -> val expectedWarnings = setOf(
"w: [InternalKotlinGradlePluginPropertiesUsed | WARNING] ATTENTION! This build uses the following Kotlin Gradle Plugin properties:"
)
val cleanedOutput = (expectedWarnings + additionalExpectedWarnings).fold(output) { acc, s ->
acc.replace(s, "") acc.replace(s, "")
} }
val warnings = cleanedOutput val warnings = cleanedOutput
@@ -176,7 +179,6 @@ fun BuildResult.assertNoBuildWarnings(
} }
val expectedK2KaptWarnings = setOf( val expectedK2KaptWarnings = setOf(
"w: [InternalKotlinGradlePluginPropertiesUsed | WARNING] ATTENTION! This build uses the following Kotlin Gradle Plugin properties:",
"w: Kapt currently doesn't support language version 2.0+. Falling back to 1.9." "w: Kapt currently doesn't support language version 2.0+. Falling back to 1.9."
) )
@@ -162,10 +162,17 @@ internal class GradleKotlinCompilerWork @Inject constructor(
severity = CompilerMessageSeverity.EXCEPTION, severity = CompilerMessageSeverity.EXCEPTION,
message = "Daemon compilation failed: ${e.message}\n${e.stackTraceToString()}" message = "Daemon compilation failed: ${e.message}\n${e.stackTraceToString()}"
) )
val recommendation = """
Try ./gradlew --stop if this issue persists
If it does not look related to your configuration, please file an issue with logs to https://kotl.in/issue
""".trimIndent()
if (!config.compilerExecutionSettings.useDaemonFallbackStrategy) { if (!config.compilerExecutionSettings.useDaemonFallbackStrategy) {
throw RuntimeException( throw RuntimeException(
"Failed to compile with Kotlin daemon. Fallback strategy (compiling without Kotlin daemon) is turned off. " + """
"Try ./gradlew --stop if this issue persists.", |Failed to compile with Kotlin daemon.
|Fallback strategy (compiling without Kotlin daemon) is turned off.
|$recommendation
""".trimMargin(),
e e
) )
} }
@@ -174,7 +181,7 @@ internal class GradleKotlinCompilerWork @Inject constructor(
""" """
|Failed to compile with Kotlin daemon: $failDetails |Failed to compile with Kotlin daemon: $failDetails
|Using fallback strategy: Compile without Kotlin daemon |Using fallback strategy: Compile without Kotlin daemon
|Try ./gradlew --stop if this issue persists. |$recommendation
""".trimMargin() """.trimMargin()
) )
} }
@@ -238,7 +238,7 @@ internal val KotlinCompilerExecutionStrategy.asFinishLogMessage: String
get() = "Finished executing kotlin compiler using $this strategy" get() = "Finished executing kotlin compiler using $this strategy"
internal fun KotlinLogger.logFinish(strategy: KotlinCompilerExecutionStrategy) { internal fun KotlinLogger.logFinish(strategy: KotlinCompilerExecutionStrategy) {
debug(strategy.asFinishLogMessage) info(strategy.asFinishLogMessage)
} }
internal fun exitCodeFromProcessExitCode(log: KotlinLogger, code: Int): ExitCode { internal fun exitCodeFromProcessExitCode(log: KotlinLogger, code: Int): ExitCode {