Spring StopWatch报错：无法停止未运行实例的问题排查与解决

问题背景 #

这个StopWatch是现有通用日志功能的一部分，该功能包含一个过滤器，会根据任务名称启动计时器。我推测报错是因为StopWatch从未启动导致的，请问如何确保它正常启动？

相关代码 #

override fun filter(exchange: ServerWebExchange, chain: WebFilterChain): Mono<Void> {
    val stopWatch = StopWatch().apply { start() }

    val headersToLog = exchange.request.headers.toSingleValueMap()
        .entries
        .filter { reqHeadersToLog.contains(it.key.lowercase(Locale.getDefault())) }
        .associate { it.key to it.value }

    fun handleReturn(pubStatus: String) {
        stopWatch.currentTaskName()?.let { stopWatch.stop() }
        val statusCode = exchange.response.statusCode?.name ?: "UNKNOWN_STATUS"

        logger.info(
            json.encodeToString(
                with(exchange.request) {
                    AccessLogEntry(
                        httpMethod = method?.name ?: "UNKNOWN_METHOD",
                        requestedUri = path.pathWithinApplication().value(),
                        httpStatusCode = statusCode,
                        durationMillis = stopWatch.totalTimeMillis,
                        host = remoteAddress?.hostString ?: "UNKNOWN_HOST",
                        pubStatus = pubStatus,
                        requestHeaders = headersToLog,
                    )
                }
            )
        )
    }


}


)}

抛出异常 #

java.lang.IllegalStateException: 无法停止StopWatch：它未处于运行状态
    at org.springframework.util.StopWatch.stop(StopWatch.java:154)
    at se.atg.caspr.commons.spring.webflux.AccessLoggingFilter.filter$handleReturn(AccessLoggingFilter.kt:32)
    at se.atg.caspr.commons.spring.webflux.AccessLoggingFilter.filter$lambda-7(AccessLoggingFilter.kt:54)
    at 

解决方法 #

• 先判断运行状态再停止：你当前用currentTaskName()?.let { stopWatch.stop() }的逻辑有问题——调用start()不传任务名称时，currentTaskName()会返回null，导致stop()不执行；如果handleReturn被多次调用，第一次stop后再次调用就会触发异常。直接用isRunning判断更可靠：

  fun handleReturn(pubStatus: String) {
      if (stopWatch.isRunning) {
          stopWatch.stop()
      }
      // 后续日志代码保持不变
  }
  

• 确保回调只执行一次：WebFlux是响应式编程模型，你的过滤器代码目前没有正确处理chain.filter(exchange)的订阅逻辑，可能导致handleReturn被多次触发。补全响应式链，确保请求成功/失败时各调用一次回调：

  override fun filter(exchange: ServerWebExchange, chain: WebFilterChain): Mono<Void> {
      val stopWatch = StopWatch().apply { start() }
  
      val headersToLog = exchange.request.headers.toSingleValueMap()
          .entries
          .filter { reqHeadersToLog.contains(it.key.lowercase(Locale.getDefault())) }
          .associate { it.key to it.value }
  
      fun handleReturn(pubStatus: String) {
          if (stopWatch.isRunning) {
              stopWatch.stop()
          }
          val statusCode = exchange.response.statusCode?.name ?: "UNKNOWN_STATUS"
  
          logger.info(
              json.encodeToString(
                  with(exchange.request) {
                      AccessLogEntry(
                          httpMethod = method?.name ?: "UNKNOWN_METHOD",
                          requestedUri = path.pathWithinApplication().value(),
                          httpStatusCode = statusCode,
                          durationMillis = stopWatch.totalTimeMillis,
                          host = remoteAddress?.hostString ?: "UNKNOWN_HOST",
                          pubStatus = pubStatus,
                          requestHeaders = headersToLog,
                      )
                  }
              )
          )
      }
  
      return chain.filter(exchange)
          .doOnSuccess { handleReturn("SUCCESS") }
          .doOnError { handleReturn("ERROR") }
  }
  

• 可选：启动时指定任务名称：如果希望currentTaskName()有值，可以在启动时传入任务名，避免null判断的歧义：

  val stopWatch = StopWatch().apply { start("access-log-timer") }
  

内容的提问来源于stack exchange，提问作者Pramod