From c61a79e2998830dff09556af12410b6f7a0ff143 Mon Sep 17 00:00:00 2001 From: Him188 Date: Fri, 13 May 2022 14:55:08 +0100 Subject: [PATCH] Add trace logging for event listener, with system property `mirai.event.trace` --- docs/DebuggingNetwork.md | 1 + .../commonMain/kotlin/event/EventListeners.kt | 13 +++++++++++++ .../commonMain/kotlin/event/SafeListener.kt | 19 ++++++++++++++++++- .../kotlin/event/AbstractEventTest.kt | 6 +++++- 4 files changed, 37 insertions(+), 2 deletions(-) diff --git a/docs/DebuggingNetwork.md b/docs/DebuggingNetwork.md index ea74306a8..eebf6eb67 100644 --- a/docs/DebuggingNetwork.md +++ b/docs/DebuggingNetwork.md @@ -25,6 +25,7 @@ | `mirai.network.show.verbose.packets` | `true`/`false` | 在日志记录数据包时包含冗长的数据包 (如 `MessageSvc.PbGetMsg`, `OnlinePush.ReqPush`, `StatSvc.SimpleGet`) | | `mirai.network.show.packet.details` | `true`/`false` | 在日志记录数据包时包含 mirai 解析结果 | | `mirai.event.show.verbose.events` | `true`/`false` | 在日志记录事件时包含冗长的事件 (如 `GroupMessagePreSendEvent`, `GroupMessagePostSendEvent`) | +| `mirai.event.trace` | `true`/`false` | 在日志记录事件监听器创建及使用的信息 | | `mirai.message.allow.sending.file.message` | `true`/`false` | 允许发送 `FileMessage`, 用于兼容旧代码 ([#1715]) | | `mirai.jce.deserializer.debug` | `true`/`false` | 启用数据包解析错误的详细信息显示 | diff --git a/mirai-core/src/commonMain/kotlin/event/EventListeners.kt b/mirai-core/src/commonMain/kotlin/event/EventListeners.kt index fbdb18e0a..366cc061d 100644 --- a/mirai-core/src/commonMain/kotlin/event/EventListeners.kt +++ b/mirai-core/src/commonMain/kotlin/event/EventListeners.kt @@ -15,6 +15,10 @@ import kotlinx.coroutines.supervisorScope import kotlinx.coroutines.sync.withLock import net.mamoe.mirai.event.* import net.mamoe.mirai.internal.network.components.EVENT_LAUNCH_UNDISPATCHED +import net.mamoe.mirai.utils.MiraiLogger +import net.mamoe.mirai.utils.info +import net.mamoe.mirai.utils.systemProp +import net.mamoe.mirai.utils.withSwitch import java.util.* import java.util.concurrent.ConcurrentLinkedQueue import kotlin.reflect.KClass @@ -27,6 +31,12 @@ internal class ListenerRegistry( internal class EventListeners { + companion object { + private val logger by lazy { + MiraiLogger.Factory.create(EventListeners::class).withSwitch(systemProp("mirai.event.trace", false)) + } + } + private val map: Map> init { @@ -85,6 +95,7 @@ internal class EventListeners { } internal fun addListener(eventClass: KClass, listener: Listener) { + logger.info { "Add listener: $listener for $eventClass" } val listeners = get(listener.priority) @Suppress("UNCHECKED_CAST") @@ -101,6 +112,7 @@ internal class EventListeners { listener: Listener, event: E, ) { + logger.info { "Invoke listener: $listener" } when (listener.concurrencyKind) { ConcurrencyKind.LOCKED -> { (listener as SafeListener).lock!!.withLock { @@ -115,5 +127,6 @@ internal class EventListeners { } } } + logger.info { "Finished listener: $listener" } } } \ No newline at end of file diff --git a/mirai-core/src/commonMain/kotlin/event/SafeListener.kt b/mirai-core/src/commonMain/kotlin/event/SafeListener.kt index cdedf5b4b..f6960c6e1 100644 --- a/mirai-core/src/commonMain/kotlin/event/SafeListener.kt +++ b/mirai-core/src/commonMain/kotlin/event/SafeListener.kt @@ -14,6 +14,7 @@ import kotlinx.coroutines.sync.Mutex import net.mamoe.mirai.event.* import net.mamoe.mirai.event.events.BotEvent import net.mamoe.mirai.utils.MiraiLogger +import net.mamoe.mirai.utils.systemProp import kotlin.coroutines.CoroutineContext /** @@ -25,6 +26,7 @@ internal class SafeListener internal constructor( private val listenerBlock: suspend (E) -> ListeningStatus, override val concurrencyKind: ConcurrencyKind, override val priority: EventPriority, + private val creationStacktrace: Exception? = if (traceEnabled) Exception() else null ) : Listener, CompletableJob by SupervisorJob(parentJob) { // avoid being cancelled on handling event private val subscriberContext: CoroutineContext = subscriberContext + this // override Job. @@ -34,6 +36,19 @@ internal class SafeListener internal constructor( else -> null } + override fun toString(): String { + return if (creationStacktrace != null) { + "SafeListener(concurrency=${concurrencyKind}" + + ", priority=$priority" + + ", subscriberContext=${subscriberContext.minusKey(Job)}" + + ", trace=${creationStacktrace.stackTraceToString()})" + } else { + return "SafeListener(concurrency=${concurrencyKind}" + + ", priority=$priority" + + ", subscriberContext=${subscriberContext.minusKey(Job)})" // remove this + } + } + @Suppress("unused") override suspend fun onEvent(event: E): ListeningStatus { if (isCompleted || isCancelled) return ListeningStatus.STOPPED @@ -70,4 +85,6 @@ internal class SafeListener internal constructor( MiraiLogger.Factory.create(SafeListener::class) } } -} \ No newline at end of file +} + +private val traceEnabled by lazy { systemProp("mirai.event.trace", true) } \ No newline at end of file diff --git a/mirai-core/src/commonTest/kotlin/event/AbstractEventTest.kt b/mirai-core/src/commonTest/kotlin/event/AbstractEventTest.kt index 71fa02b64..12f09d7c2 100644 --- a/mirai-core/src/commonTest/kotlin/event/AbstractEventTest.kt +++ b/mirai-core/src/commonTest/kotlin/event/AbstractEventTest.kt @@ -11,4 +11,8 @@ package net.mamoe.mirai.internal.event import net.mamoe.mirai.internal.test.AbstractTest -internal abstract class AbstractEventTest : AbstractTest() \ No newline at end of file +internal abstract class AbstractEventTest : AbstractTest() { + init { + System.setProperty("mirai.event.trace", "true") + } +} \ No newline at end of file