diff --git a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/agent/DynamicClassTransformer.kt b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/agent/DynamicClassTransformer.kt index 6c8cea9f41..7971f09ccb 100644 --- a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/agent/DynamicClassTransformer.kt +++ b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/agent/DynamicClassTransformer.kt @@ -2,6 +2,8 @@ package org.utbot.instrumentation.agent import org.utbot.common.asPathToFile import org.utbot.framework.plugin.api.util.UtContext +import org.utbot.instrumentation.process.logError +import org.utbot.instrumentation.process.logInfo import java.lang.instrument.ClassFileTransformer import java.security.ProtectionDomain @@ -30,13 +32,13 @@ class DynamicClassTransformer : ClassFileTransformer { return if (pathToClassfile in pathsToUserClasses || packsToAlwaysTransform.any(className::startsWith) ) { - System.err.println("Transforming: $className") + logInfo { "Transforming: $className" } transformer.transform(loader, className, classBeingRedefined, protectionDomain, classfileBuffer) } else { null } } catch (e: Throwable) { - System.err.println("Error while transforming: ${e.stackTraceToString()}") + logError { "Error while transforming: ${e.stackTraceToString()}" } throw e } finally { UtContext.currentContext()?.stopWatch?.start() diff --git a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/instrumentation/et/TraceHandler.kt b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/instrumentation/et/TraceHandler.kt index 8f69bd5089..75d0cef781 100644 --- a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/instrumentation/et/TraceHandler.kt +++ b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/instrumentation/et/TraceHandler.kt @@ -9,6 +9,7 @@ import org.objectweb.asm.MethodVisitor import org.objectweb.asm.Opcodes import org.objectweb.asm.Type import org.objectweb.asm.commons.LocalVariablesSorter +import org.utbot.instrumentation.process.logError sealed class InstructionData { abstract val line: Int @@ -111,6 +112,8 @@ class ProcessingStorage { * Storage to which instrumented classes will write execution data. */ object RuntimeTraceStorage { + internal var alreadyLoggedIncreaseStackSizeTip = false + /** * Contains ids of instructions in the order of execution. */ @@ -151,7 +154,11 @@ object RuntimeTraceStorage { this.`$__trace__`[current] = id this.`$__counter__` = current + 1 } else { - System.err.println("Stack overflow (increase stack size Settings.TRACE_ARRAY_SIZE)") + val loggedTip = alreadyLoggedIncreaseStackSizeTip + if (!loggedTip) { + alreadyLoggedIncreaseStackSizeTip = true + logError { "Stack overflow (increase stack size Settings.TRACE_ARRAY_SIZE)" } + } } } } @@ -289,5 +296,6 @@ class TraceHandler { fun resetTrace() { instructionsList = null RuntimeTraceStorage.`$__counter__` = 0 + RuntimeTraceStorage.alreadyLoggedIncreaseStackSizeTip = false } } \ No newline at end of file diff --git a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/process/ChildProcess.kt b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/process/ChildProcess.kt index 7350e406d5..60aa4b6529 100644 --- a/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/process/ChildProcess.kt +++ b/utbot-instrumentation/src/main/kotlin/org/utbot/instrumentation/process/ChildProcess.kt @@ -69,36 +69,32 @@ private val logLevel = ChildProcessLogLevel.Info // Logging private val dateFormatter: DateTimeFormatter = DateTimeFormatter.ofPattern("HH:mm:ss.SSS") -private fun log(level: ChildProcessLogLevel, any: () -> Any?) { +private inline fun log(level: ChildProcessLogLevel, any: () -> Any?) { if (level < logLevel) return - System.err.println(LocalDateTime.now().format(dateFormatter) + " | ${any()}") + System.err.println(LocalDateTime.now().format(dateFormatter) + " ${level.name.uppercase()}| ${any()}") } // errors that must be address -private fun logError(any: () -> Any?) { +internal inline fun logError(any: () -> Any?) { log(ChildProcessLogLevel.Error, any) } -private fun logException(e: Throwable) { - log(ChildProcessLogLevel.Error) { "$e |> ${e.stackTraceToString()}" } -} - // default log level for irregular useful messages that does not pollute log -private fun logInfo(any: () -> Any?) { +internal inline fun logInfo(any: () -> Any?) { log(ChildProcessLogLevel.Info, any) } // log level for frequent messages useful for debugging -private fun logDebug(any: () -> Any?) { +internal inline fun logDebug(any: () -> Any?) { log(ChildProcessLogLevel.Debug, any) } // log level for internal rd logs and frequent messages // heavily pollutes log, useful only when debugging rpc // probably contains no info about utbot -private fun logTrace(any: () -> Any?) { +internal fun logTrace(any: () -> Any?) { log(ChildProcessLogLevel.Trace, any) } @@ -193,7 +189,7 @@ private fun RdCall.measureExecutionForTermination(block: (T) -> R) try { block(it) } catch (e: Throwable) { - logException(e) + logError { e.stackTraceToString() } throw e } } @@ -319,7 +315,6 @@ private suspend fun initiate(lifetime: Lifetime, port: Int, pid: Int) { logInfo { "starting instrumenting" } deferred.await() } catch (e: Throwable) { - logError { "Terminating process because exception occurred" } - logException(e) + logError { "Terminating process because exception occurred: ${e.stackTraceToString()}" } } } \ No newline at end of file