feat(W46): 发送路由带上原因,并加一行 CyreneRoute 诊断日志

为什么要把「原因」也带出来
- 结果只有 Ws / Rest / Queue 三档,而「为什么是这一档」在设备上完全看不见。W45 那轮真机回归
  就卡在这里:那条消息进了补发队列、网络侧一条请求都没有,而「零请求 + 进队列」在判据里只可能
  来自 Queue 那一档;可顶栏同时显示「重连中…」。两者都只是结论,事后无法分辨「判据读到
  Offline」与「判据读了别的值」。
- 于是把判据抽成 sendRouteDecisionFor(wsDispatched, connection) -> (route, reason):reason 就是
  原来那三条规则各自的分支标识(FrameDispatched / ConnectionOffline / ConnectionNotReady)。
  sendRouteFor 现在读它的 route,所以两处不可能分叉。判据、优先级、行为逐字未改。

那一行日志(tag = CyreneRoute,Log.d,只在 DEBUG 构建打)
- 打点:ChatViewModel.sendThroughLadder 一进入就一笔,覆盖阶梯的三个分支(帧交出去 / 试 REST /
  直接进队列),一行 key=value、空格分隔:
  wsDispatched=... socket=<ChatSocket.state.value,权威值> mirror=<顶栏读的那个镜像>
  wsObject=<present|absent> route=... reason=... outcome=... fromQueue=...
- socket 与 mirror 必须同时打出来:mirror 是 collect 过来的一格,只会滞后、不会超前,两者不一致
  就说明顶栏那一刻显示的是上一格 —— 这正是「顶栏重连中…」与「这条进了队列」能同时出现的形态。
- 这是开发期诊断仪,不是产品行为:字段增删不构成兼容问题、不为它写测试(要钉的是纯函数那张全表)。
  不打 token / 请求体 / 正文 / localId。

顺带(同一轮的可观测性)
- ChatSocket 新增只读属性 hasLiveSocket(webSocket != null),只喂日志,不是产品逻辑的输入。
- 复核 WsState.Offline 的写点:ChatSocket 里只有两处(runConnectionLoop 的 ConfigMissing,以及
  endWithAuthFailure),close() 写的是 Idle;非 401 的握手失败(代理回 503)走 Closed ->
  Reconnecting,进不了这一档。

测试
- SendFallbackTest 新增两例:五档连接状态 × wsDispatched 真假的全表逐个钉住结果 + 原因,并钉住
  sendRouteFor 与判定同值;另一个钉住三个 reason 都可达、没有第四种组合。全量 1155 例,
  0 失败 0 错误。
This commit is contained in:
AskaEth committed 2026-10-05 19:50:28 +08:00
1 parent b8399b5949
commit d546f31755
4 files changed
+189 -9

No files matched your search

@@ -88,6 +88,16 @@ class ChatSocket(
/** 连接状态机;见 [WsState]。 */
val state: StateFlow<WsState> = _state.asStateFlow()
/**
* 诊断用:此刻底层连接对象还在不在(`webSocket != null`)。
*
* 只读、不改变任何行为,也**不是**产品逻辑的输入(`send` 判的是 [state] 与这个对象本身)。
* 它存在只为一件事:让「这一帧为什么没走 WS」在 logcat 里可读——[state] 与它**可能不一致**
* (状态还是 `Connected` 而对象已经被 `finally` 清空、或者反过来),而那个不一致正是
* `WsSendOutcome.Failed` 与 `Queued` 的分水岭。tag 见 `ChatViewModel.SEND_ROUTE_LOG_TAG`。
*/
val hasLiveSocket: Boolean get() = webSocket != null
private val _events = MutableSharedFlow<WsEvent>(
replay = 0,
extraBufferCapacity = EVENT_BUFFER,
@@ -2,6 +2,7 @@ package top.yeij.cyrene.ui.chat
import android.net.Uri
import android.provider.OpenableColumns
import android.util.Log
import androidx.lifecycle.ViewModel
import androidx.lifecycle.viewModelScope
import kotlinx.coroutines.CancellationException
@@ -14,6 +15,7 @@ import kotlinx.coroutines.flow.update
import kotlinx.coroutines.launch
import kotlinx.coroutines.withContext
import kotlinx.coroutines.withTimeoutOrNull
import top.yeij.cyrene.BuildConfig
import top.yeij.cyrene.app.AppContainer
import top.yeij.cyrene.app.ShareIntake
import top.yeij.cyrene.core.error.CyreneError
@@ -78,6 +80,14 @@ const val MAIN_SESSION_ID = "web"
/** 本端标识(design/16 §4.5 允许的可读前缀形态)。 */
private const val DEVICE_ID = "voiceassist:cyrene:v1"
/**
* 「发送走了哪一档、依据是哪一条」那一行诊断日志的 tag(W46)。
*
* 固定成一个好 grep 的名字,因为它是**设备上唯一能分辨「判据读到的是哪个连接状态」的东西**:
* `adb logcat -s CyreneRoute`。格式、字段与用途写在 `ChatViewModel.logSendRoute` 的 KDoc 里。
*/
const val SEND_ROUTE_LOG_TAG = "CyreneRoute"
/**
* 乐观消息:已发出、还没等到 `message_persisted` 归一的本地消息。
*
@@ -1590,8 +1600,13 @@ class ChatViewModel(
val ws = socket
val sent = ws?.sendChat(sessionId, text, DEVICE_ID, localId, parallel) ?: false
val state = ws?.state?.value ?: WsState.Idle
val outcome = wsSendOutcome(sent, state)
val decision = sendRouteDecisionFor(wsDispatched = sent, connection = state)
// 这一行是排查「发送为什么没走 WS / 为什么进了队列」的唯一现场(判据本身是纯函数,看不见它
// 读到的是哪个值)。DEBUG 才打,且**不改任何行为**:它只读、只格式化。
logSendRoute(ws, sent, state, decision, outcome, fromQueue)
when (wsSendOutcome(sent, state)) {
when (outcome) {
// 成功路径**一个字都没变**:帧交给 socket 之后这里什么都不做(补发那条顺手出队)。
// 补发出去的那条顺手把「反复失败」的记账归零([queuedResendFailures]):静默之后连接
// 恢复并补发成功 ⇒ 下一次离线又能重新告知,不会永久闭嘴。
@@ -1607,8 +1622,9 @@ class ChatViewModel(
// 未就绪 ⇒ 直接试 REST(W45)。判据是纯函数 [sendRouteFor],这里只落地:三档「还没
// 连上」(Idle / Connecting / Reconnecting)试一次;[WsState.Offline] 那一档直接进
// 队列,**一次请求都不发**(那一档会话已知是死的,试了只会把「已排队不会丢」换成
// 一次回滚 + 一句误导人的鉴权错误)。
WsSendOutcome.Queued -> when (sendRouteFor(wsDispatched = false, connection = state)) {
// 一次回滚 + 一句误导人的鉴权错误)。用的是上面**同一个** [decision]:日志里那一档
// 与真正走的那一档必须是同一次判定,分两次问就又有了「日志说一套、代码做一套」的余地。
WsSendOutcome.Queued -> when (decision.route) {
SendRoute.Rest -> sendViaRestFallback(localId, text, parallel, fromQueue)
// Ws 在这一支不可达(刚刚才问过 `sendChat`,它没把帧交出去);真出现也只可能是
@@ -1618,6 +1634,52 @@ class ChatViewModel(
}
}
/**
* 「这一次发送走了哪一档、依据是哪一条」——**一行**诊断(W46)。
*
* ## 用途与 tag
* tag 固定为 [SEND_ROUTE_LOG_TAG](`CyreneRoute`),`adb logcat -s CyreneRoute` 就能看到每一次
* 走进阶梯的投递。它回答的是一个**在设备上原本不可观测**的问题:判据 [sendRouteFor] 那一刻
* **读到的是哪个连接状态**。W45 那轮回归卡在这里——消息进了队列、网络侧一条请求都没有,而
* 「零请求 + 进队列」在判据里只可能来自 `Queue`([SendRouteReason.ConnectionOffline]),可顶栏
* 同时显示「重连中…」;两者都只是**结论**,事后再看无法分辨「判据读到 Offline」与「判据读到
* 别的值」。
*
* 字段(一行、空格分隔,`key=value`):
* - `wsDispatched=` 帧交给 socket 了没有(判据的第一个输入,就是上面那个 `sent`);
* - `socket=` **socket 自己的** [WsState](`ChatSocket.state.value`,权威值,判据的第二个输入);
* - `mirror=` 本 VM 里那个**被顶栏读**的镜像([ChatUiState.connection],只由
* [onConnectionChanged] 的 collect 写)。它**只能滞后**权威值,不会超前——两者不一致就说明
* 顶栏那一刻显示的是上一格;
* - `wsObject=` 底层连接对象还在不在(`ChatSocket.hasLiveSocket`)。`Connected` 而它是 `absent`
* 是 [WsSendOutcome.Failed] 的成因之一,值得一眼看到;
* - `route=` / `reason=` **同一次**判定的结果与依据([sendRouteDecisionFor]);
* - `outcome=` [wsSendOutcome] 那一档(判据没被问到时就靠它区分「试 REST」与「回滚」);
* - `fromQueue=` 首次发送还是队列补发。
*
* ## 它刻意不是需要长期维护的东西
* 只此一行、只在 DEBUG 打([BuildConfig.DEBUG])、tag 与字段名都不构成对外契约:字段增删改
* 不需要任何兼容处理,也不必为它写测试(要钉的是纯函数 [sendRouteDecisionFor] 的全表)。
* 不打 token / 请求体 / 正文,也不打 `localId`:这里要的是「哪一档、为什么」,那几样都不是判据的
* 输入。
*/
private fun logSendRoute(
ws: ChatSocket?,
wsDispatched: Boolean,
socketState: WsState,
decision: SendRouteDecision,
outcome: WsSendOutcome,
fromQueue: Boolean,
) {
if (!BuildConfig.DEBUG) return
Log.d(
SEND_ROUTE_LOG_TAG,
"wsDispatched=$wsDispatched socket=$socketState mirror=${_state.value.connection}" +
" wsObject=${if (ws?.hasLiveSocket == true) "present" else "absent"}" +
" route=${decision.route} reason=${decision.reason} outcome=$outcome fromQueue=$fromQueue",
)
}
/**
* 直接试 REST(W45;形状与 W41 一样:WS 未就绪时用既有的 `POST /api/v1/chat`(`stream:true`)
* 把这条发出去)。
@@ -61,6 +61,48 @@ enum class SendRoute {
Queue,
}
/**
* [sendRouteFor] 那条判据**依据的是哪一条**([sendRouteDecisionFor] 的取值,W46)。
*
* 为什么把「原因」也变成返回值:结果只有三档,而「为什么是这一档」在真机上是**看不见的**。W45
* 那轮回归就卡在这儿——界面上那条消息进了队列(`queuedForConnection`)、网络侧一条请求都没有,
* 而「零请求 + 进队列」在判据里只可能来自 [SendRoute.Queue];可顶栏同时显示「重连中…」。事后只看
* 结果与顶栏,两种可能(判据读到 [WsState.Offline] vs 判据读了另一个值)**在外同形**。于是这一行
* 日志把依据本身也打出来(tag 见 `ChatViewModel.SEND_ROUTE_LOG_TAG`),矛盾就能当场分辨。
*
* 三档**与 [sendRouteFor] 的三条规则一一对应**,没有第四种可能:它是那条 `when` 的分支标识,
* 不是另算一遍的近似值([sendRouteFor] 就是本函数的 `.route`)。
*/
enum class SendRouteReason {
/** 规则 1:`wsDispatched` ⇒ 帧已经交给 socket,连接状态不参与判断。 */
FrameDispatched,
/** 规则 2:连接是 [WsState.Offline](会话已知是死的)⇒ 进队列,**一个请求都不发**。 */
ConnectionOffline,
/** 规则 3:其余未就绪档([WsState.Idle] / [WsState.Connecting] / [WsState.Reconnecting])⇒ 直接试 REST。 */
ConnectionNotReady,
}
/**
* 一次路由判定的**结果 + 依据**([sendRouteDecisionFor] 的取值)。
*
* 两者必须同出一次:分开问两次会把「判据看到的事实」与「结论」割开,而那正是排查时最容易错的地方。
*/
data class SendRouteDecision(val route: SendRoute, val reason: SendRouteReason)
/**
* 同 [sendRouteFor],但把「依据」一并带出来([SendRouteReason],W46 可观测性)。
*
* 判据、优先级、行为**逐字未改**:下面这个 `when` 就是 [sendRouteFor] 原来那一个,只是每一支把
* 自己标了出来。[sendRouteFor] 现在读它的 [SendRouteDecision.route],所以两处不可能分叉。
*/
fun sendRouteDecisionFor(wsDispatched: Boolean, connection: WsState): SendRouteDecision = when {
wsDispatched -> SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)
connection == WsState.Offline -> SendRouteDecision(SendRoute.Queue, SendRouteReason.ConnectionOffline)
else -> SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady)
}
/**
* 回落 REST 宣告失败之后的落点([restFailureLanding] 的取值)。
*/
@@ -108,15 +150,15 @@ enum class RestFailureLanding {
*
* 判据只认 `Connected` **一个值**(不是「不等于 Offline」之类的近似)——连接状态的另外四档
* 都意味着帧没有被交给任何服务端。
*
* 本函数只回三个结果;**「为什么是这一档」在 [sendRouteDecisionFor]**(W46 加的可观测性,判据本身
* 一字未动):真机上看不见「判据读到的是哪个值」,而那正是排查「发送为什么进了队列」时唯一要分的
* 东西。
*/
fun sendRouteFor(
wsDispatched: Boolean,
connection: WsState,
): SendRoute = when {
wsDispatched -> SendRoute.Ws
connection == WsState.Offline -> SendRoute.Queue
else -> SendRoute.Rest
}
): SendRoute = sendRouteDecisionFor(wsDispatched, connection).route
/**
* 这份回执照的是「**服务端已经收下这条**」(受理起回合 / 忙时续接排队 / 早就收过这条幂等键)。
@@ -26,7 +26,7 @@ import top.yeij.cyrene.domain.chat.SendChannel
* 现在的判据里**没有任何探测输入**:路由只看「帧交出去了没有 + 这一刻的连接状态」两个事实,
* REST 那一次的产物由 [restAttemptLanding] 判落点。
*
* ## 本测试钉住六件事
* ## 本测试钉住七件事
* 1. **优先级**([sendRouteFor]):帧交出去了 ⇒ 走 WS(连接状态不再参与);未就绪且不是
* [WsState.Offline] ⇒ 直接试 REST;[WsState.Offline] ⇒ 进队列、**一个请求都不发**。
* 2. **收下了就不进队列**:受理 / 续接排队 / 幂等重复([ChatAck.isAccepted] 那一族)⇒
@@ -36,6 +36,9 @@ import top.yeij.cyrene.domain.chat.SendChannel
* 4. **服务端给过裁决 ⇒ 回滚**:拒绝的回执(`409` / `500` / `503` / `400`)与 401 / 配置类异常。
* 5. **两个超时**:连接超时落在 2~3 秒(无网时的等待上界),整通上限另设且不许拉长。
* 6. **这条阶梯到不了「REST 专属」的消息**(有图 / 有附件一律在进入阶梯之前就被判成 REST)。
* 7. **「为什么是这一档」**([sendRouteDecisionFor],W46):五档连接状态 × `wsDispatched` 真假那
* 十个格子逐个钉住**结果 + 原因**。结果是给代码看的,原因是给**设备上的日志**看的——真机上
* 看不见判据读到的是哪个连接状态,而那正是排查「发送为什么进了队列」时唯一要分的东西。
*/
class SendFallbackTest {
@@ -124,6 +127,69 @@ class SendFallbackTest {
}
}
// —— 一之二、判据的「原因」(W46 可观测性) ——
@Test
fun `the whole table carries which rule decided it`() {
// 结果只有三档,而「**为什么**是这一档」在真机上看不见:W45 那轮真机回归里,那条消息进了
// 队列、网络侧一条请求都没有,而「零请求 + 进队列」在判据里只可能来自 Queue;可顶栏同时
// 显示「重连中…」。只看结果分不出「判据读到 Offline」与「判据读了别的值」,所以要有个地方
// 能把依据本身取出来——同时打给 logcat(tag `CyreneRoute`)与这条全表。
//
// 表还是五档 × 帧交出去了没有那十个格子,只是每一格多钉一个原因;并顺手钉住
// `sendRouteFor` 就是它的 `.route`(两处**不可能**分叉,日志里那一档与真正走的那一档必然
// 是同一次判定的结果)。
val table = listOf(
Triple(true, WsState.Idle, SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)),
Triple(true, WsState.Connecting, SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)),
Triple(true, WsState.Reconnecting, SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)),
Triple(true, WsState.Connected, SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)),
Triple(true, WsState.Offline, SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched)),
Triple(false, WsState.Idle, SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady)),
Triple(false, WsState.Connecting, SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady)),
Triple(false, WsState.Reconnecting, SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady)),
Triple(false, WsState.Connected, SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady)),
// 唯一能在**一个请求都不发**的前提下进队列的那一格(也正是排查时要认出来的那一格)。
Triple(false, WsState.Offline, SendRouteDecision(SendRoute.Queue, SendRouteReason.ConnectionOffline)),
)
table.forEach { (dispatched, connection, expected) ->
val decision = sendRouteDecisionFor(wsDispatched = dispatched, connection = connection)
assertEquals(
"dispatched=$dispatched / $connection 的结果与依据",
expected,
decision,
)
assertEquals(
"dispatched=$dispatched / $connection 上 sendRouteFor 必须与判定同值",
expected.route,
sendRouteFor(wsDispatched = dispatched, connection = connection),
)
}
}
@Test
fun `every reason is reachable and each rule owns exactly one`() {
// 原因这一栏与三条规则**一一对应**:每一个取值都必须能在全表里被取到(将来加了规则却没人
// 标出来,这条会红),而且「结果 + 原因」不会出现两种组合指向同一个结果这种糊法。
val reachable = listOf(true, false).flatMap { dispatched ->
WsState.entries.map { sendRouteDecisionFor(dispatched, it).reason }
}.toSet()
assertEquals(SendRouteReason.entries.toSet(), reachable)
val combos = listOf(true, false).flatMap { dispatched ->
WsState.entries.map { sendRouteDecisionFor(dispatched, it) }
}.toSet()
// 十格只有三组(结果,原因):`Ws` 一格、`Rest` 一格、`Queue` 一格,没有第四种组合。
assertEquals(
setOf(
SendRouteDecision(SendRoute.Ws, SendRouteReason.FrameDispatched),
SendRouteDecision(SendRoute.Rest, SendRouteReason.ConnectionNotReady),
SendRouteDecision(SendRoute.Queue, SendRouteReason.ConnectionOffline),
),
combos,
)
}
// —— 二、直接试 REST 的落点 ——
@Test