Rework re-init, fix #282

mirai-core-qqandroid/build.gradle.kts

@@ -85,6 +85,7 @@ kotlin {
         val jvmMain by getting {
             dependencies {
                 runtimeOnly(files("build/classes/kotlin/jvm/main")) // classpath is not properly set by IDE
+                //    api(kotlinx("coroutines-debug", "1.3.5"))
                 api(kotlinx("serialization-runtime", Versions.Kotlin.serialization))
                 //api(kotlinx("serialization-protobuf", Versions.Kotlin.serialization))
 

mirai-core-qqandroid/src/commonMain/kotlin/net/mamoe/mirai/qqandroid/QQAndroidBot.common.kt

@@ -58,7 +58,6 @@ import kotlin.contracts.ExperimentalContracts
 import kotlin.contracts.contract
 import kotlin.coroutines.CoroutineContext
 import kotlin.jvm.JvmSynthetic
-import kotlin.jvm.Synchronized
 import kotlin.math.absoluteValue
 import kotlin.random.Random
 import net.mamoe.mirai.qqandroid.network.protocol.data.jce.FriendInfo as JceFriendInfo
@@ -294,7 +293,7 @@ internal abstract class QQAndroidBotBase constructor(
     }
 
     override fun createNetworkHandler(coroutineContext: CoroutineContext): QQAndroidBotNetworkHandler {
-        return QQAndroidBotNetworkHandler(this as QQAndroidBot)
+        return QQAndroidBotNetworkHandler(coroutineContext, this as QQAndroidBot)
     }
 
     override val groups: ContactList<Group> = ContactList(LockFreeLinkedList())

mirai-core-qqandroid/src/commonMain/kotlin/net/mamoe/mirai/qqandroid/contact/FriendImpl.kt

@@ -14,6 +14,8 @@ package net.mamoe.mirai.qqandroid.contact
 
 import kotlinx.atomicfu.AtomicInt
 import kotlinx.atomicfu.atomic
+import kotlinx.coroutines.Job
+import kotlinx.coroutines.SupervisorJob
 import kotlinx.io.core.Closeable
 import net.mamoe.mirai.LowLevelAPI
 import net.mamoe.mirai.contact.Friend
@@ -59,10 +61,12 @@ internal inline fun Friend.checkIsFriendImpl(): FriendImpl {
 
 internal class FriendImpl(
     bot: QQAndroidBot,
-    override val coroutineContext: CoroutineContext,
+    coroutineContext: CoroutineContext,
     override val id: Long,
     private val friendInfo: FriendInfo
 ) : Friend() {
+    override val coroutineContext: CoroutineContext = coroutineContext + SupervisorJob(coroutineContext[Job])
+
     @Suppress("unused") // bug
     val lastMessageSequence: AtomicInt = atomic(-1)
 

mirai-core-qqandroid/src/commonMain/kotlin/net/mamoe/mirai/qqandroid/contact/GroupImpl.kt

@@ -12,6 +12,8 @@
 
 package net.mamoe.mirai.qqandroid.contact
 
+import kotlinx.coroutines.Job
+import kotlinx.coroutines.SupervisorJob
 import kotlinx.coroutines.launch
 import kotlinx.io.core.Closeable
 import net.mamoe.mirai.LowLevelAPI
@@ -28,12 +30,10 @@ import net.mamoe.mirai.qqandroid.message.MessageSourceToGroupImpl
 import net.mamoe.mirai.qqandroid.message.ensureSequenceIdAvailable
 import net.mamoe.mirai.qqandroid.message.firstIsInstanceOrNull
 import net.mamoe.mirai.qqandroid.network.highway.HighwayHelper
-import net.mamoe.mirai.qqandroid.network.protocol.data.proto.ImMsgBody
 import net.mamoe.mirai.qqandroid.network.protocol.packet.chat.TroopManagement
 import net.mamoe.mirai.qqandroid.network.protocol.packet.chat.image.ImgStore
 import net.mamoe.mirai.qqandroid.network.protocol.packet.chat.receive.MessageSvc
 import net.mamoe.mirai.qqandroid.network.protocol.packet.list.ProfileService
-import net.mamoe.mirai.qqandroid.utils.encodeToString
 import net.mamoe.mirai.qqandroid.utils.estimateLength
 import net.mamoe.mirai.utils.*
 import kotlin.contracts.ExperimentalContracts
@@ -61,13 +61,16 @@ internal fun Group.checkIsGroupImpl() {
 @OptIn(MiraiExperimentalAPI::class, LowLevelAPI::class)
 @Suppress("PropertyName")
 internal class GroupImpl(
-    bot: QQAndroidBot, override val coroutineContext: CoroutineContext,
+    bot: QQAndroidBot,
+    coroutineContext: CoroutineContext,
     override val id: Long,
     groupInfo: GroupInfo,
     members: Sequence<MemberInfo>
 ) : Group() {
     companion object;
 
+    override val coroutineContext: CoroutineContext = coroutineContext + SupervisorJob(coroutineContext[Job])
+
     override val bot: QQAndroidBot by bot.unsafeWeakRef()
 
     val uin: Long = groupInfo.uin

mirai-core-qqandroid/src/commonMain/kotlin/net/mamoe/mirai/qqandroid/contact/MemberImpl.kt

@@ -13,6 +13,8 @@ package net.mamoe.mirai.qqandroid.contact
 
 import kotlinx.atomicfu.AtomicInt
 import kotlinx.atomicfu.atomic
+import kotlinx.coroutines.Job
+import kotlinx.coroutines.SupervisorJob
 import kotlinx.coroutines.launch
 import net.mamoe.mirai.LowLevelAPI
 import net.mamoe.mirai.contact.*
@@ -42,10 +44,11 @@ import kotlin.jvm.JvmSynthetic
 internal class MemberImpl constructor(
     val qq: FriendImpl, // 不要 WeakRef
     group: GroupImpl,
-    override val coroutineContext: CoroutineContext,
+    coroutineContext: CoroutineContext,
     memberInfo: MemberInfo
 ) : Member() {
     override val group: GroupImpl by group.unsafeWeakRef()
+    override val coroutineContext: CoroutineContext = coroutineContext + SupervisorJob(coroutineContext[Job])
 
     @Suppress("unused") // false positive
     val lastMessageSequence: AtomicInt = atomic(-1)

mirai-core-qqandroid/src/commonMain/kotlin/net/mamoe/mirai/qqandroid/network/QQAndroidBotNetworkHandler.kt

@@ -46,18 +46,19 @@ import net.mamoe.mirai.qqandroid.utils.retryCatching
 import net.mamoe.mirai.utils.*
 import kotlin.coroutines.CoroutineContext
 import kotlin.jvm.Volatile
+import kotlin.random.Random
 import kotlin.time.ExperimentalTime
 
 @Suppress("MemberVisibilityCanBePrivate")
 @OptIn(MiraiInternalAPI::class)
-internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler() {
+internal class QQAndroidBotNetworkHandler(coroutineContext: CoroutineContext, bot: QQAndroidBot) : BotNetworkHandler() {
     override val bot: QQAndroidBot by bot.unsafeWeakRef()
-    override val supervisor: CompletableJob = SupervisorJob(bot.coroutineContext[Job])
+    override val supervisor: CompletableJob = SupervisorJob(coroutineContext[Job])
     override val logger: MiraiLogger get() = bot.configuration.networkLoggerSupplier(this)
 
-    override val coroutineContext: CoroutineContext = bot.coroutineContext + CoroutineExceptionHandler { _, throwable ->
+    override val coroutineContext: CoroutineContext = coroutineContext + CoroutineExceptionHandler { _, throwable ->
         logger.error("Exception in NetworkHandler", throwable)
-    }
+    } + supervisor
 
     private lateinit var channel: PlatformSocket
 
@@ -209,10 +210,17 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
     internal var pendingIncomingPackets: LockFreeLinkedList<KnownPacketFactories.IncomingPacket<*>>? =
         LockFreeLinkedList()
 
+    private var initFriendOk = false
+    private var initGroupOk = false
+
     /**
      * Don't use concurrently
      */
     suspend fun reloadFriendList() {
+        if (initFriendOk) {
+            return
+        }
+
         logger.info { "开始加载好友信息" }
         var currentFriendCount = 0
         var totalFriendCount: Short
@@ -242,6 +250,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             // delay(200)
         }
         logger.info { "好友列表加载完成, 共 ${currentFriendCount}个" }
+        initFriendOk = true
     }
 
     suspend fun StTroopNum.reloadGroup() {
@@ -280,20 +289,25 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
     }
 
     suspend fun reloadGroupList() {
+        if (initGroupOk) {
+            return
+        }
+
         logger.info { "开始加载群组列表与群成员列表" }
         val troopListData = FriendList.GetTroopListSimplify(bot.client)
-            .sendAndExpect<FriendList.GetTroopListSimplify.Response>(retry = 3)
+            .sendAndExpect<FriendList.GetTroopListSimplify.Response>(retry = 5)
 
-        troopListData.groups.chunked(50).forEach { chunk ->
+        troopListData.groups.chunked(30).forEach { chunk ->
             coroutineScope {
                 chunk.forEach {
                     launch {
-                        retryCatching(3) { it.reloadGroup() }.getOrThrow()
+                        retryCatching(5) { it.reloadGroup() }.getOrThrow()
                     }
                 }
             }
         }
         logger.info { "群组列表与群成员加载完成, 共 ${troopListData.groups.size}个" }
+        initGroupOk = true
     }
 
     @OptIn(MiraiExperimentalAPI::class, ExperimentalTime::class)
@@ -302,8 +316,12 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
         check(this@QQAndroidBotNetworkHandler.isActive) { "network is dead therefore can't init" }
 
         CancellationException("re-init").let { reInitCancellationException ->
-            bot.friends.delegate.clear { it.cancel(reInitCancellationException) }
-            bot.groups.delegate.clear { it.cancel(reInitCancellationException) }
+            if (!initFriendOk) {
+                bot.friends.delegate.clear { it.cancel(reInitCancellationException) }
+            }
+            if (!initGroupOk) {
+                bot.groups.delegate.clear { it.cancel(reInitCancellationException) }
+            }
         }
 
         if (!pendingEnabled) {
@@ -313,7 +331,12 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
 
         coroutineScope {
             launch { reloadFriendList() }
-            launch { reloadGroupList() }
+            launch {
+                if (Random.nextInt() > 50) {
+                    error("boom")
+                }
+                reloadGroupList()
+            }
         }
 
         this@QQAndroidBotNetworkHandler.launch {
@@ -325,7 +348,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             when (resp) {
                 null -> logger.info { "Missing ConfigPushSvc.PushReq." }
                 is ConfigPushSvc.PushReq.PushReqResponse.Success -> {
-                    logger.info { "ConfigPushSvc.PushReq: success" }
+                    logger.info { "ConfigPushSvc.PushReq: Success" }
                 }
                 is ConfigPushSvc.PushReq.PushReqResponse.ChangeServer -> {
                     logger.info { "Server requires reconnect." }
@@ -340,28 +363,39 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             }
         }
 
+        logger.info { "Syncing friend message history..." }
         withTimeoutOrNull(30000) {
             launch { syncFromEvent<MessageSvc.PbGetMsg.GetMsgSuccess, Unit> { Unit } }
             MessageSvc.PbGetMsg(bot.client, MsgSvc.SyncFlag.START, currentTimeSeconds).sendAndExpect<Packet>()
         } ?: error("timeout syncing friend message history")
+        logger.info { "Syncing friend message history: Success" }
 
         bot.firstLoginSucceed = true
 
         _pendingEnabled.value = false
         pendingIncomingPackets?.forEach {
-            @Suppress("UNCHECKED_CAST")
-            KnownPacketFactories.handleIncomingPacket(
-                it as KnownPacketFactories.IncomingPacket<Packet>,
-                bot,
-                it.flag2,
-                it.consumer
-            )
+            runCatching {
+                @Suppress("UNCHECKED_CAST")
+                KnownPacketFactories.handleIncomingPacket(
+                    it as KnownPacketFactories.IncomingPacket<Packet>,
+                    bot,
+                    it.flag2,
+                    it.consumer
+                )
+            }.getOrElse {
+                logger.error("Exception on processing pendingIncomingPackets", it)
+            }
         }
         val list = pendingIncomingPackets
         pendingIncomingPackets = null // release, help gc
         list?.clear() // help gc
 
-        BotOnlineEvent(bot).broadcast()
+        runCatching {
+            BotOnlineEvent(bot).broadcast()
+        }.getOrElse {
+            logger.error("Exception on broadcasting BotOnlineEvent", it)
+        }
+
         Unit // dont remove. can help type inference
     }
 
@@ -583,9 +617,9 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
      * 不推荐使用它, 可能产生意外的情况.
      */
     suspend fun OutgoingPacket.sendWithoutExpect() {
-        check(bot.isActive) { "bot is dead therefore can't send any packet" }
+        check(bot.isActive) { "bot is dead therefore can't send ${this.commandName}" }
         check(this@QQAndroidBotNetworkHandler.isActive) { "network is dead therefore can't send any packet" }
-        logger.verbose("Send: ${this.commandName}")
+        logger.verbose { "Send: ${this.commandName}" }
         channel.send(delegate)
     }
 
@@ -598,7 +632,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
         require(timeoutMillis > 100) { "timeoutMillis must > 100" }
         require(retry >= 0) { "retry must >= 0" }
 
-        check(bot.isActive) { "bot is dead therefore can't send any packet" }
+        check(bot.isActive) { "bot is dead therefore can't send ${this.commandName}" }
         check(this@QQAndroidBotNetworkHandler.isActive) { "network is dead therefore can't send any packet" }
 
         suspend fun doSendAndReceive(handler: PacketListener, data: Any, length: Int): E {
@@ -607,8 +641,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
                 is ByteReadPacket -> channel.send(data)
                 else -> error("Internal error: unexpected data type: ${data::class.simpleName}")
             }
-
-            logger.verbose { "Send done: $commandName" }
+            logger.verbose { "Send: $commandName" }
 
             @Suppress("UNCHECKED_CAST")
             return withTimeoutOrNull(timeoutMillis) {
@@ -651,6 +684,12 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             this.commandName == commandName && this.sequenceId == sequenceId
     }
 
+    init {
+        this.supervisor.invokeOnCompletion {
+            close(it)
+        }
+    }
+
     override fun close(cause: Throwable?) {
         if (::channel.isInitialized) {
             channel.close()

mirai-core/src/commonMain/kotlin/net.mamoe.mirai/BotImpl.kt

@@ -173,7 +173,7 @@ abstract class BotImpl<N : BotNetworkHandler> constructor(
                         if (e.killBot) {
                             throw e
                         } else {
-                            logger.warning("Login failed. Retrying in 3s...")
+                            logger.warning { "Login failed. Retrying in 3s..." }
                             _network.closeAndJoin(e)
                             delay(3000)
                             continue
@@ -182,35 +182,34 @@ abstract class BotImpl<N : BotNetworkHandler> constructor(
                         network.logger.error(e)
                         _network.closeAndJoin(e)
                     }
-                    logger.warning("Login failed. Retrying in 3s...")
+                    logger.warning { "Login failed. Retrying in 3s..." }
                     delay(3000)
                 }
             }
 
             suspend fun doInit() {
-                retryCatching(2) { count, lastException ->
+                retryCatching(5) { count, lastException ->
                     if (count != 0) {
                         if (!isActive) {
                             logger.error("Cannot init due to fatal error")
-                            if (lastException == null) {
-                                logger.error("<no exception>")
-                            } else {
-                                logger.error(lastException)
-                            }
+                            throw lastException ?: error("<No lastException>")
                         }
-                        logger.warning("Init failed. Retrying in 3s...")
+                        logger.warning { "Init failed. Retrying in 3s..." }
                         delay(3000)
                     }
+
                     _network.init()
                 }.getOrElse {
-                    network.logger.error(it)
-                    logger.error("Cannot init. some features may be affected")
+                    logger.error { "Cannot init. some features may be affected" }
+                    throw it // abort
                 }
             }
 
             // logger.info("Initializing BotNetworkHandler")
 
             if (::_network.isInitialized) {
+                _network.cancel(CancellationException("manual re-login", cause = cause))
+
                 BotReloginEvent(this, cause).broadcast()
                 doRelogin()
                 return
@@ -220,7 +219,7 @@ abstract class BotImpl<N : BotNetworkHandler> constructor(
             doInit()
         }
 
-        logger.info("Logging in...")
+        logger.info { "Logging in..." }
         if (::_network.isInitialized) {
             network.withConnectionLock {
                 @OptIn(ThisApiMustBeUsedInWithConnectionLockBlock::class)
@@ -230,7 +229,7 @@ abstract class BotImpl<N : BotNetworkHandler> constructor(
             @OptIn(ThisApiMustBeUsedInWithConnectionLockBlock::class)
             reinitializeNetworkHandler(null)
         }
-        logger.info("Login successful")
+        logger.info { "Login successful" }
     }
 
     protected abstract fun createNetworkHandler(coroutineContext: CoroutineContext): N
@@ -241,7 +240,7 @@ abstract class BotImpl<N : BotNetworkHandler> constructor(
     init {
         coroutineContext[Job]!!.invokeOnCompletion { throwable ->
             network.close(throwable)
-            offlineListener.cancel(CancellationException("bot cancelled", throwable))
+            offlineListener.cancel(CancellationException("Bot cancelled", throwable))
 
             groups.delegate.clear() // job is cancelled, so child jobs are to be cancelled
             friends.delegate.clear()

mirai-core/src/commonMain/kotlin/net.mamoe.mirai/network/BotNetworkHandler.kt

@@ -40,6 +40,7 @@ import net.mamoe.mirai.utils.WeakRefProperty
  *
  * @suppress 此为**内部 API**, 可能在任意时刻被改动, 且不会给出任何警告.
  */
+@MiraiInternalAPI
 @Suppress("PropertyName")
 abstract class BotNetworkHandler : CoroutineScope {
 
@@ -122,6 +123,7 @@ abstract class BotNetworkHandler : CoroutineScope {
     }
 }
 
+@MiraiInternalAPI
 @OptIn(MiraiInternalAPI::class)
 suspend fun BotNetworkHandler.closeAndJoin(cause: Throwable? = null) {
     this.close(cause)

mirai-core/src/commonMain/kotlin/net.mamoe.mirai/utils/BotConfiguration.kt

@@ -31,6 +31,7 @@ open class BotConfiguration {
     /**
      * 网络层日志构造器
      */
+    @OptIn(MiraiInternalAPI::class)
     var networkLoggerSupplier: ((BotNetworkHandler) -> MiraiLogger) = { DefaultLogger("Network(${it.bot.id})") }
 
     /**
@@ -85,6 +86,7 @@ open class BotConfiguration {
     /**
      * 不显示网络日志
      */
+    @OptIn(MiraiInternalAPI::class)
     @ConfigurationDsl
     fun noNetworkLog() {
         networkLoggerSupplier = { _: BotNetworkHandler -> SilentLogger }