Faster init: saved 200ms for each load

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

@@ -33,6 +33,8 @@ import net.mamoe.mirai.utils.*
 import net.mamoe.mirai.utils.io.*
 import kotlin.coroutines.CoroutineContext
 import kotlin.jvm.Volatile
+import kotlin.time.ExperimentalTime
+import kotlin.time.measureTime
 
 @Suppress("MemberVisibilityCanBePrivate")
 @UseExperimental(MiraiInternalAPI::class)
@@ -106,8 +108,8 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
         StatSvc.Register(bot.client).sendAndExpect<StatSvc.Register.Response>(6000) // it's slow
     }
 
-    @UseExperimental(MiraiExperimentalAPI::class)
-    override suspend fun init() {
+    @UseExperimental(MiraiExperimentalAPI::class, ExperimentalTime::class)
+    override suspend fun init(): Unit = coroutineScope {
         this@QQAndroidBotNetworkHandler.subscribeAlways<ForceOfflineEvent> {
             if (this@QQAndroidBotNetworkHandler.bot == this.bot) {
                 this.bot.logger.error("被挤下线")
@@ -117,12 +119,11 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
 
         MessageSvc.PbGetMsg(bot.client, MsgSvc.SyncFlag.START, currentTimeSeconds).sendWithoutExpect()
 
-        //val msg = MessageSvc.PbGetMsg(bot.client, MsgSvc.SyncFlag.START, currentTimeSeconds).sendAndExpect<MessageSvc.PbGetMsg.Response>()
-        //println(msg.contentToString())
         bot.qqs.delegate.clear()
         bot.groups.delegate.clear()
 
-        val startTime = currentTimeMillis
+        val friendListLoadTime = async {
+            measureTime {
                 try {
                     bot.logger.info("开始加载好友信息")
                     var currentFriendCount = 0
@@ -153,10 +154,13 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
                 } catch (e: Exception) {
                     bot.logger.error("加载好友列表失败|一般这是由于加载过于频繁导致/将以热加载方式加载好友列表")
                 }
+            }
+        }
 
-        val friendLoadFinish = currentTimeMillis
         val groupInfo = mutableMapOf<Long, Int>()
-        coroutineScope {
+
+        val groupTime = async {
+            measureTime {
                 try {
                     bot.logger.info("开始加载群组列表与群成员列表")
                     val troopListData = FriendList.GetTroopListSimplify(bot.client)
@@ -198,11 +202,11 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
                         bot.groups.delegate.addLast(group)
                         launch {
                             try {
-                            getTroopMemberList(group, contactList, troopNum.dwGroupOwnerUin)
+                                fillTroopMemberList(group, contactList, troopNum.dwGroupOwnerUin)
                                 groupInfo[troopNum.groupCode] = contactList.size
                             } catch (e: Exception) {
                                 groupInfo[troopNum.groupCode] = -1
-                            bot.logger.info("群${troopNum.groupCode}的列表拉取失败, 将采用动态加入")
+                                bot.logger.warning("群${troopNum.groupCode}的列表拉取失败, 将采用动态加入")
                                 bot.logger.error(e)
                             }
                         }
@@ -213,6 +217,8 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
                     bot.logger.error(e)
                 }
             }
+        }
+
         //===log===//
         fun fillUntil(long: Number, size: Int): String {
             val x = long.toString()
@@ -225,9 +231,11 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             )
         }
 
+        joinAll(friendListLoadTime, groupTime)
+
         bot.logger.info("====================Mirai Bot List初始化完毕====================")
-        bot.logger.info("好友数量: ${fillUntil(bot.qqs.size, 9)}\t\t\t 加载时间: ${friendLoadFinish - startTime}ms")
-        bot.logger.info("加入群组: ${fillUntil(bot.groups.size, 9)}\t\t\t 加载时间: ${currentTimeMillis - friendLoadFinish}ms")
+        bot.logger.info("好友数量: ${fillUntil(bot.qqs.size, 9)}\t\t\t 加载时间: ${friendListLoadTime.await().inMilliseconds}ms")
+        bot.logger.info("加入群组: ${fillUntil(bot.groups.size, 9)}\t\t\t 加载时间: ${groupTime.await().inMilliseconds}ms")
         groupInfo.forEach {
             if (it.value == -1) {
                 bot.logger.error("群组号码: ${fillUntil(it.key, 9)}\t 成员数量加载失败")
@@ -242,11 +250,22 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
         }
         bot.logger.info("====================Mirai Bot List初始化完毕====================")
 
-        bot.firstLoginSucceed = true
-
-        launch {
+        this@QQAndroidBotNetworkHandler.launch(CoroutineName("Heartbeat")) {
             while (this.isActive) {
                 delay(bot.configuration.heartbeatPeriodMillis)
+                val failException = doHeartBeat()
+                if (failException != null) {
+                    delay(bot.configuration.firstReconnectDelayMillis)
+                    close()
+                    bot.tryReinitializeNetworkHandler(failException)
+                }
+            }
+        }
+
+        bot.firstLoginSucceed = true
+    }
+
+    suspend fun doHeartBeat(): Exception? {
         var lastException: Exception?
         try {
             check(
@@ -256,20 +275,15 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
                         retry = 1
                     ) is StatSvc.GetOnlineStatus.Response.Success
             )
-                    continue
+            return null
         } catch (e: Exception) {
             lastException = e
         }
-                delay(bot.configuration.firstReconnectDelayMillis)
-                close()
-                bot.tryReinitializeNetworkHandler(lastException)
-            }
+        return lastException
     }
-    }
-
 
-    suspend fun getTroopMemberList(group: GroupImpl, list: ContactList<Member>, owner: Long): ContactList<Member> {
-        bot.logger.info("开始获取群[${group.uin}]成员列表")
+    suspend fun fillTroopMemberList(group: GroupImpl, list: ContactList<Member>, owner: Long) {
+        bot.logger.verbose("开始获取群[${group.uin}]成员列表")
         var size = 0
         var nextUin = 0L
         while (true) {
@@ -306,10 +320,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
             if (nextUin == 0L) {
                 break
             }
-            //println("已获取群[${group.uin}]成员列表前" + size + "个成员")
         }
-        //println("群[${group.uin}]成员全部获取完成, 共${list.size}个成员")
-        return list
     }
 
     /**
@@ -473,7 +484,7 @@ internal class QQAndroidBotNetworkHandler(bot: QQAndroidBot) : BotNetworkHandler
         cachedPacketTimeoutJob = launch {
             delay(1000)
             if (cachedPacketTimeoutJob == this.coroutineContext[Job] && cachedPacket.getAndSet(null) != null) {
-                PacketLogger.verbose("等待另一部分包时超时. 将舍弃已接收的半个包")
+                PacketLogger.verbose { "等待另一部分包时超时. 将舍弃已接收的半个包" }
             }
         }
     }