Improve console shutdown (#2016)

* Try to improve console shutdown

* Resetting & Better java calling

* Dump crash report when timed out to shutdown

* Ensure `CoroutineScope.cancel()` working; rename to `shutdown`

* Signal handlers

* Force halt system to avoid some magic errors
This commit is contained in:
微莹·纤绫 2022-06-07 00:10:51 +08:00 committed by GitHub
parent 0b67a6783a
commit d0c1848c94
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
9 changed files with 455 additions and 24 deletions

View File

@ -12,8 +12,7 @@
package net.mamoe.mirai.console
import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.Job
import kotlinx.coroutines.*
import me.him188.kotlin.dynamic.delegation.dynamicDelegation
import net.mamoe.mirai.Bot
import net.mamoe.mirai.BotFactory
@ -239,6 +238,22 @@ public interface MiraiConsole : CoroutineScope {
@ConsoleExperimentalApi("This is a low-level API and might be removed in the future.")
public val isActive: Boolean
get() = job.isActive
/**
* 停止 Console 运行
*
* Console 会在一个合适的时间进行关闭, 并不是调用马上关闭 Console
*/
@ConsoleExperimentalApi
@JvmStatic
public fun shutdown() {
val consoleJob = job
if (!consoleJob.isActive) return
@OptIn(DelicateCoroutinesApi::class)
GlobalScope.launch {
MiraiConsoleImplementation.shutdown()
}
}
}

View File

@ -28,6 +28,7 @@ import net.mamoe.mirai.console.internal.data.builtins.ConsoleDataScopeImpl
import net.mamoe.mirai.console.internal.logging.LoggerControllerImpl
import net.mamoe.mirai.console.internal.plugin.BuiltInJvmPluginLoaderImpl
import net.mamoe.mirai.console.internal.pluginManagerImpl
import net.mamoe.mirai.console.internal.shutdown.ShutdownDaemon
import net.mamoe.mirai.console.logging.LoggerController
import net.mamoe.mirai.console.plugin.Plugin
import net.mamoe.mirai.console.plugin.jvm.JvmPluginLoader
@ -396,10 +397,29 @@ public interface MiraiConsoleImplementation : CoroutineScope {
override val resolvedPlugins: MutableList<Plugin> get() = MiraiConsole.pluginManagerImpl.resolvedPlugins
}
internal suspend fun shutdown() {
val bridge = currentBridge ?: return
if (!bridge.isActive) return
bridge.shutdownDaemon.tryStart()
Bot.instances.forEach { bot ->
lateinit var logger: MiraiLogger
kotlin.runCatching {
logger = bot.logger
bot.closeAndJoin()
}.onFailure { t ->
kotlin.runCatching { logger.error("Error in closing bot", t) }
}
}
MiraiConsole.job.cancelAndJoin()
}
init {
Runtime.getRuntime().addShutdownHook(thread(false) {
Runtime.getRuntime().addShutdownHook(thread(false, name = "Mirai Console Shutdown Hook") {
if (instanceInitialized) {
runBlocking { MiraiConsole.job.cancelAndJoin() }
runBlocking {
shutdown()
}
}
})
}

View File

@ -11,7 +11,6 @@ package net.mamoe.mirai.console.command
import kotlinx.coroutines.DelicateCoroutinesApi
import kotlinx.coroutines.GlobalScope
import kotlinx.coroutines.cancelAndJoin
import kotlinx.coroutines.launch
import kotlinx.coroutines.sync.Mutex
import kotlinx.coroutines.sync.withLock
@ -54,7 +53,6 @@ import net.mamoe.mirai.console.util.ConsoleInternalApi
import net.mamoe.mirai.console.util.sendAnsiMessage
import net.mamoe.mirai.event.events.EventCancelledException
import net.mamoe.mirai.utils.BotConfiguration
import net.mamoe.mirai.utils.MiraiLogger
import java.lang.management.ManagementFactory
import java.lang.management.MemoryMXBean
import java.lang.management.MemoryUsage
@ -140,16 +138,7 @@ public object BuiltInCommands {
if (!MiraiConsole.isActive) return@withLock
sendMessage("Stopping mirai-console")
kotlin.runCatching {
Bot.instances.forEach { bot ->
lateinit var logger: MiraiLogger
kotlin.runCatching {
logger = bot.logger
bot.closeAndJoin()
}.onFailure { t ->
kotlin.runCatching { logger.error("Error in closing bot", t) }
}
}
MiraiConsole.job.cancelAndJoin()
MiraiConsoleImplementation.shutdown()
}.fold(
onSuccess = {
runIgnoreException<EventCancelledException> { sendMessage("mirai-console stopped successfully.") }

View File

@ -43,6 +43,7 @@ import net.mamoe.mirai.console.internal.logging.LoggerControllerImpl
import net.mamoe.mirai.console.internal.logging.MiraiConsoleLogger
import net.mamoe.mirai.console.internal.permission.BuiltInPermissionService
import net.mamoe.mirai.console.internal.plugin.PluginManagerImpl
import net.mamoe.mirai.console.internal.shutdown.ShutdownDaemon
import net.mamoe.mirai.console.internal.util.runIgnoreException
import net.mamoe.mirai.console.logging.LoggerController
import net.mamoe.mirai.console.permission.PermissionService
@ -58,6 +59,7 @@ import net.mamoe.mirai.utils.*
import java.time.Instant
import java.time.ZoneId
import java.time.format.DateTimeFormatter
import java.util.concurrent.atomic.AtomicBoolean
import kotlin.contracts.InvocationKind
import kotlin.contracts.contract
import kotlin.reflect.KProperty
@ -85,6 +87,7 @@ internal class MiraiConsoleImplementationBridge(
// used internally
val globalComponentStorage: GlobalComponentStorageImpl by lazy { GlobalComponentStorageImpl() }
val shutdownDaemon = ShutdownDaemon.DaemonStarter(this)
// tentative workaround for https://github.com/mamoe/mirai/pull/1889#pullrequestreview-887903183
@Volatile
@ -147,6 +150,7 @@ internal class MiraiConsoleImplementationBridge(
}
MiraiConsole.job.invokeOnCompletion {
shutdownDaemon.tryStart()
Bot.instances.forEach { kotlin.runCatching { it.close() }.exceptionOrNull()?.let(mainLogger::error) }
}
}

View File

@ -18,6 +18,7 @@ import net.mamoe.mirai.console.data.runCatchingLog
import net.mamoe.mirai.console.extension.PluginComponentStorage
import net.mamoe.mirai.console.internal.data.mkdir
import net.mamoe.mirai.console.internal.extension.GlobalComponentStorage
import net.mamoe.mirai.console.internal.shutdown.ShutdownDaemon
import net.mamoe.mirai.console.permission.Permission
import net.mamoe.mirai.console.permission.PermissionService
import net.mamoe.mirai.console.plugin.Plugin
@ -89,7 +90,13 @@ internal abstract class JvmPluginInternal(
internal fun internalOnDisable() {
firstRun = false
kotlin.runCatching {
onDisable()
val crtThread = Thread.currentThread()
ShutdownDaemon.pluginDisablingThreads.add(crtThread)
try {
onDisable()
} finally {
ShutdownDaemon.pluginDisablingThreads.remove(crtThread)
}
}.fold(
onSuccess = {
cancel(CancellationException("plugin disabled"))

View File

@ -0,0 +1,309 @@
/*
* Copyright 2019-2022 Mamoe Technologies and contributors.
*
* 此源代码的使用受 GNU AFFERO GENERAL PUBLIC LICENSE version 3 许可证的约束, 可以在以下链接找到该许可证.
* Use of this source code is governed by the GNU AGPLv3 license that can be found through the following link.
*
* https://github.com/mamoe/mirai/blob/dev/LICENSE
*/
package net.mamoe.mirai.console.internal.shutdown
import kotlinx.coroutines.*
import net.mamoe.mirai.console.MiraiConsole
import net.mamoe.mirai.console.internal.MiraiConsoleImplementationBridge
import net.mamoe.mirai.console.internal.pluginManagerImpl
import net.mamoe.mirai.console.plugin.PluginManager.INSTANCE.description
import net.mamoe.mirai.utils.debug
import java.io.File
import java.io.FileDescriptor
import java.io.FileOutputStream
import java.io.PrintStream
import java.lang.management.ManagementFactory
import java.lang.reflect.Method
import java.nio.file.Paths
import java.time.Instant
import java.time.ZoneOffset
import java.util.*
import java.util.concurrent.ConcurrentLinkedDeque
import java.util.concurrent.Executors
import java.util.concurrent.ThreadFactory
import java.util.concurrent.atomic.AtomicBoolean
import java.util.concurrent.atomic.AtomicInteger
import kotlin.io.path.writeText
internal object ShutdownDaemon {
@Suppress("RemoveRedundantQualifierName")
internal class DaemonStarter(
private val consoleImplementationBridge: MiraiConsoleImplementationBridge
) {
private val started = AtomicBoolean(false)
fun tryStart() {
if (started.compareAndSet(false, true)) {
ShutdownDaemon.start(consoleImplementationBridge)
}
}
}
private object ThreadInfoJava9Access {
private val isDaemonM: Method?
private val getPriorityM: Method?
init {
var idm: Method? = null
var gpm: Method? = null
kotlin.runCatching {
val klass = Class.forName("java.lang.management.ThreadInfo")
val mts = klass.methods.asSequence()
idm = mts.firstOrNull { it.name == "isDaemon" }
gpm = mts.firstOrNull { it.name == "getPriority" }
}
isDaemonM = idm
getPriorityM = gpm
}
fun isDaemon(inf: Any): Boolean {
isDaemonM?.invoke(inf)?.let { return it as Boolean }
return false
}
fun getPriority(inf: Any): Int {
getPriorityM?.invoke(inf)?.let { return it as Int }
return -1
}
val canGetPri: Boolean get() = getPriorityM != null
}
val pluginDisablingThreads = ConcurrentLinkedDeque<Thread>()
private val Thread.State.isWaiting: Boolean
get() = this == Thread.State.WAITING || this == Thread.State.TIMED_WAITING
@OptIn(DelicateCoroutinesApi::class)
private fun start(bridge: MiraiConsoleImplementationBridge) {
val crtThread = Thread.currentThread()
val isConsoleRunning = AtomicBoolean(true)
// 1 thread to run main daemon
// 1 thread to listen console shutdown running
// 1 thread reserved
val executor = Executors.newFixedThreadPool(3, object : ThreadFactory {
private val counter = AtomicInteger(0)
override fun newThread(r: Runnable): Thread {
return Thread(r, "Mirai Console Shutdown Daemon #" + counter.getAndIncrement()).also {
it.isDaemon = true
}
}
})
executor.execute {
listen(crtThread, isConsoleRunning)
executor.shutdown()
}
GlobalScope.launch(executor.asCoroutineDispatcher()) {
bridge.coroutineContext.job.join()
isConsoleRunning.set(false)
}
bridge.mainLogger.debug { "SHUTDOWN DAEMON STARTED........." }
}
@Suppress("MemberVisibilityCanBePrivate")
fun dumpCrashReport(saveError: Boolean) {
val isAndroidSystem = kotlin.runCatching { Class.forName("android.util.Log") }.isSuccess
val sb = StringBuilder(1024).append("\n\n")
val now = System.currentTimeMillis()
sb.append("=============================================================\n")
sb.append("MIRAI CONSOLE CRASH REPORT.\n")
sb.append("Console has take too long to shutdown.\n\n")
sb.append("TIME: ").append(now).append(" <")
fun msgAfterTimeDump() {
sb.append(">\nSYSTEM: ").append(System.getProperty("os.name")).append(" ")
.append(System.getProperty("os.arch")).append(" ").append(System.getProperty("os.version"))
sb.append("\nJRT:\n ")
sb.append(System.getProperty("java.runtime.name"))
sb.append(" ").append(System.getProperty("java.version"))
sb.append("\n by ").append(System.getProperty("java.vendor"))
sb.append("\nSPEC:\n ").append(System.getProperty("java.specification.name")).append(" ")
.append(System.getProperty("java.specification.version"))
sb.append("\n by ").append(System.getProperty("java.specification.vendor"))
sb.append("\nVM:\n ").append(System.getProperty("java.vm.name")).append(" ")
.append(System.getProperty("java.vm.version"))
sb.append("\n by ").append(System.getProperty("java.vm.vendor"))
sb.append("\n\n")
kotlin.runCatching {
sb.append("\nPROCESS Working dir: ").append(File("a").absoluteFile.parent ?: File(".").absoluteFile)
sb.append("\nConsole Working Dir: ").append(MiraiConsole.rootPath.toAbsolutePath())
}
sb.append("\nLoaded plugins:\n")
kotlin.runCatching {
MiraiConsole.pluginManagerImpl.resolvedPlugins.forEach { plugin ->
val desc = plugin.description
sb.append("|- ").append(desc.name).append(" v").append(desc.version).append('\n')
sb.append("| `- ID: ").append(desc.id).append('\n')
desc.author.takeUnless { it.isBlank() }?.let {
sb.append("| `- AUTHOR: ").append(it).append('\n')
}
sb.append("| `- MAIN: ").append(plugin.javaClass).append('\n')
plugin.javaClass.protectionDomain?.codeSource?.location?.let { from ->
@Suppress("IntroduceWhenSubject")
val f: Any = when {
from.protocol == "file" -> Paths.get(from.toURI())
else -> from
}
sb.append("| `- FROM: ").append(f).append('\n')
}
}
}
sb.append("\n\n\n")
}
if (isAndroidSystem) {
sb.append(Date(now))
msgAfterTimeDump()
sb.append("\n\nTHREADS:\n\n")
val threads = Thread.getAllStackTraces()
threads.forEach { (thread, stackTrace) ->
sb.append("\n\n\n").append(thread).append('\n')
stackTrace.forEach { stack ->
sb.append('\t').append(stack).append('\n')
}
}
} else {
object { // Android doesn't contain management system & classing boxing
fun a() {
sb.append(Instant.ofEpochMilli(now).atOffset(ZoneOffset.UTC))
msgAfterTimeDump()
val rtMxBean = ManagementFactory.getRuntimeMXBean()
sb.append("PROCESS: ").append(rtMxBean.name)
sb.append("\nVM OPTIONS:\n")
rtMxBean.inputArguments.forEach { cmd ->
sb.append(" ").append(cmd).append("\n")
}
sb.append("\n\nTHREADS:\n\n")
val threadMxBean = ManagementFactory.getThreadMXBean()
val infs = threadMxBean.dumpAllThreads(true, true)
infs.forEach { inf ->
sb.append("\n\n").append('"')
sb.append(inf.threadName)
sb.append('"')
if (ThreadInfoJava9Access.isDaemon(inf)) {
sb.append(" daemon")
}
if (ThreadInfoJava9Access.canGetPri) {
sb.append(" prio=").append(ThreadInfoJava9Access.getPriority(inf))
}
sb.append(" Id=").append(inf.threadId)
inf.lockName?.let { sb.append(" on ").append(it) }
inf.lockOwnerName?.let { lon ->
sb.append(" owned by \"").append(lon)
sb.append("\" Id=").append(inf.lockOwnerId)
}
if (inf.isSuspended) sb.append(" (suspended)")
if (inf.isInNative) sb.append(" (in native)")
sb.append('\n')
val lockInf = inf.lockInfo
val lockedMonitors = inf.lockedMonitors
inf.stackTrace.forEachIndexed { index, stackTraceElement ->
sb.append("\tat ").append(stackTraceElement).append('\n')
if (index == 0 && lockInf != null) {
when (inf.threadState!!) {
Thread.State.BLOCKED -> {
sb.append("\t- blocked on ").append(lockInf).append('\n')
}
Thread.State.WAITING,
Thread.State.TIMED_WAITING -> {
sb.append("\t- waiting on ").append(lockInf).append('\n')
}
else -> {}
}
}
lockedMonitors.forEach { mi ->
if (mi.lockedStackDepth == index) {
sb.append("\t- locked ").append(mi).append('\n')
}
}
}
sb.append("\n\n")
}
}
}.a()
}
sb.append("\n\n")
val report = sb.toString()
if (!isAndroidSystem && saveError) {
kotlin.runCatching {
PrintStream(FileOutputStream(FileDescriptor.err)).println(report)
}
}
if (saveError) {
val fileName = "CONSOLE_CRASH_REPORT_${now}.log"
kotlin.runCatching {
MiraiConsole.rootPath.resolve(fileName).writeText(report)
}.recoverCatching {
if (!isAndroidSystem) {
File("CONSOLE_CRASH_REPORT_${now}.log").writeText(report)
}
}
}
kotlin.runCatching {
MiraiConsole.mainLogger.error(report)
}
}
private fun listen(thread: Thread, consoleRunning: AtomicBoolean) {
val startTime = System.currentTimeMillis()
val timeout = 1000L * 60
while (consoleRunning.get()) {
val crtTime = System.currentTimeMillis()
if (crtTime - startTime >= timeout) {
kotlin.runCatching {
dumpCrashReport(saveError = true)
}
pluginDisablingThreads.forEach { threadKill(it) }
threadKill(thread)
pluginDisablingThreads.clear()
return
}
Thread.sleep(1000)
// Force intercept known death codes
pluginDisablingThreads.forEach { pluginCrtThread ->
val stackTraces by lazy { pluginCrtThread.stackTrace }
if (pluginCrtThread.state.isWaiting) {
/// java.desktop:
// WToolkit 关闭后执行 java.awt.Window.dispose() 会堵死在 native code
for (i in 0 until stackTraces.size.coerceAtMost(10)) {
val stack = stackTraces[i]
if (stack.className.startsWith("java.awt.") && stack.methodName.contains(
"dispose",
ignoreCase = true
)
) {
pluginCrtThread.interrupt()
break
}
}
}
}
}
}
private fun threadKill(thread: Thread) {
thread.interrupt()
Thread.sleep(10)
if (!thread.isAlive) return
Thread.sleep(100)
if (!thread.isAlive) return
Thread.sleep(500)
@Suppress("DEPRECATION")
if (thread.isAlive) thread.stop()
}
}

View File

@ -69,7 +69,7 @@ internal fun startupConsoleThread() {
} catch (e: CancellationException) {
return@launch
} catch (e: UserInterruptException) {
BuiltInCommands.StopCommand.run { ConsoleCommandSender.handle() }
signalHandler("INT")
return@launch
} catch (eof: EndOfFileException) {
consoleLogger.warning("Closing input service...")

View File

@ -120,6 +120,7 @@ open class MiraiConsoleImplementationTerminal
get() = ConsoleTerminalSettings.launchOptions
override fun preStart() {
registerSignalHandler()
overrideSTD(this)
}
}
@ -143,6 +144,7 @@ val terminal: Terminal = run {
.jansi(true)
.dumb(true)
.paused(true)
.signalHandler { signalHandler(it.name) }
.build()
.let { terminal ->
if (terminal is AbstractWindowsTerminal) {

View File

@ -19,9 +19,7 @@
package net.mamoe.mirai.console.terminal
import kotlinx.coroutines.CancellationException
import kotlinx.coroutines.CoroutineScope
import kotlinx.coroutines.runBlocking
import kotlinx.coroutines.*
import net.mamoe.mirai.console.MiraiConsole
import net.mamoe.mirai.console.MiraiConsoleImplementation
import net.mamoe.mirai.console.MiraiConsoleImplementation.Companion.start
@ -31,9 +29,17 @@ import net.mamoe.mirai.console.util.ConsoleExperimentalApi
import net.mamoe.mirai.console.util.ConsoleInternalApi
import net.mamoe.mirai.message.data.Message
import net.mamoe.mirai.utils.childScope
import net.mamoe.mirai.utils.debug
import net.mamoe.mirai.utils.verbose
import org.jline.utils.Signals
import java.io.FileDescriptor
import java.io.FileOutputStream
import java.io.PrintStream
import java.lang.Runnable
import java.util.concurrent.Executors
import java.util.concurrent.ThreadFactory
import java.util.concurrent.atomic.AtomicBoolean
import java.util.concurrent.atomic.AtomicInteger
import kotlin.system.exitProcess
/**
@ -46,15 +52,18 @@ object MiraiConsoleTerminalLoader {
startAsDaemon()
try {
runBlocking {
MiraiConsole.job.invokeOnCompletion {
Thread.sleep(1000) // 保证错误信息打印完全
exitProcess(0)
MiraiConsole.job.invokeOnCompletion { err ->
if (err != null) {
Thread.sleep(1000) // 保证错误信息打印完全
}
}
MiraiConsole.job.join()
}
} catch (e: CancellationException) {
// ignored
}
// Avoid plugin started some non-daemon threads
exitProcessAndForceHalt(0)
}
@ConsoleTerminalExperimentalApi
@ -171,6 +180,82 @@ internal object ConsoleDataHolder : AutoSavePluginDataHolder,
get() = "Terminal"
}
private val shutdownSignals = arrayOf(
"INT", "TERM", "QUIT"
)
internal val signalHandler: (String) -> Unit = initSignalHandler()
private fun initSignalHandler(): (String) -> Unit {
val shutdownMonitorLock = AtomicBoolean(false)
return handler@{ signalName ->
// JLine may process other signals
MiraiConsole.mainLogger.verbose { "Received signal $signalName" }
if (signalName !in shutdownSignals) return@handler
MiraiConsole.mainLogger.debug { "Handled signal $signalName" }
MiraiConsole.shutdown()
// Shutdown by signal requires process be killed
if (shutdownMonitorLock.compareAndSet(false, true)) {
val pool = Executors.newFixedThreadPool(2, object : ThreadFactory {
private val counter = AtomicInteger()
override fun newThread(r: Runnable): Thread {
return Thread(r, "Mirai Console Signal-Shutdown Daemon #" + counter.getAndIncrement()).also {
it.isDaemon = true
}
}
})
@OptIn(DelicateCoroutinesApi::class)
GlobalScope.launch(pool.asCoroutineDispatcher()) {
MiraiConsole.job.join()
delay(15000)
// Force kill process if plugins started non-daemon threads
exitProcessAndForceHalt(-5)
}
}
}
}
internal fun registerSignalHandler() {
fun reg(name: String) {
Signals.register(name) { signalHandler(name) }
}
shutdownSignals.forEach { reg(it) }
}
internal fun exitProcessAndForceHalt(code: Int): Nothing {
MiraiConsole.mainLogger.debug { "[exitProcessAndForceHalt] called with code $code" }
val exitFuncName = arrayOf("exit", "halt")
val shutdownClasses = arrayOf("java.lang.System", "java.lang.Runtime", "java.lang.Shutdown")
val isShutdowning = Thread.getAllStackTraces().asSequence().flatMap {
it.value.asSequence()
}.any { stackTrace ->
stackTrace.className in shutdownClasses && stackTrace.methodName in exitFuncName
}
MiraiConsole.mainLogger.debug { "[exitProcessAndForceHalt] isShutdowning = $isShutdowning" }
val task = Runnable {
Thread.sleep(15000L)
runCatching { net.mamoe.mirai.console.internal.shutdown.ShutdownDaemon.dumpCrashReport(true) }
val fc = when (code) {
0 -> 5784171
else -> code
}
MiraiConsole.mainLogger.debug { "[exitProcessAndForceHalt] timed out, force halt with code $fc" }
Runtime.getRuntime().halt(fc)
}
if (isShutdowning) {
task.run()
error("Runtime.halt returned normally, while it was supposed to halt JVM.")
} else {
Thread(task, "Mirai Console Force Halt Daemon").start()
exitProcess(code)
}
}
internal fun overrideSTD(terminal: MiraiConsoleImplementation) {
if (ConsoleTerminalSettings.noConsole) {
SystemOutputPrintStream // Avoid StackOverflowError when launch with no console mode