V1.4.8: 按现场日志复盘优化取址等待与远程日志(含 15 秒白等修复)

依据用户提供的 1.4.7 现场日志(21 行,5 次点歌全部成功)复盘出四点:

1. 【行为,最大】每次点歌白等 15 秒。
   日志里每首歌前都有一条「JS-BRIDGE 15s 未就绪」,紧跟着「NATIVE-SONG 取址成功 用时=3xx~7xxms」——
   即取址本身只要 0.3~0.7 秒,但用户从按下点歌到开始下载要等 15.7 秒。
   原因: 桥一旦不可用,SongApiClient 每次都仍等满 15 秒。
   修复: KtvJsBridge 新增「已判定不可用」状态(markUnavailable/isUnavailable),
   首次判定后后续点歌直接走原生通道;桥万一恢复(热更新重载成功)自动清除该状态。

2. 【日志去噪】持久状态只记一次。
   原来「15s 未就绪」按每次点歌一条 WARN 输出,一天几百条且无新增信息。
   现在只在状态首次变化时记一条 ERROR。

3. 【可定位】补上"为什么不可用"。
   旧日志里没有任何 KtvApi 未导出/WebView 初始化失败的行,说明 init 回调根本没触发。
   KtvJsBridge.init 增加 20 秒看门狗: onPageFinished 未回调时明确上报
   「初始化超时:onPageFinished 未回调或 KtvApi 未导出」;
   init 异常与 KtvApi 未导出也统一收敛到 markUnavailable。

4. 【上下文完整】启动关键行不再有 undefined。
   旧日志的 STORAGE 行 serverip/clientip/user/traceid 全是 undefined(记在设备上下文之前),
   而且 AppPaths.storageFacts() 会真实建目录、写探针、读 /proc/mounts —— 却跑在主线程。
   现在把 STORAGE 移入 reportDeviceBootInfo() 的后台线程、在 refreshLogDeviceContext()
   与 MiliLog.awaitServerIp() 之后上报: 上下文完整且不再阻塞主线程。

5. 【新增状态样本】每 6 小时一条 HEALTH(版本/在线/可用空间/曲库是否存在及大小/根目录)。
   日志此前只有事件没有状态样本,无法排查"随时间变化"的问题(空间变少、曲库丢失、长期离线)。

6. 【字段一致】「请求源=」不再为空: 走原生兜底时 JS 的 reportSongResult 不会触发,
   现在 SongUrlResolver 记录 lastHost,SongApiClient.lastSongSourceHost() 依次回退。

AGENTS.md 增补「写日志的五条约定」(只记一次/上下文完整/不做重活/可自我定位/状态样本+事件)。

版本 1.4.7(27) 到 1.4.8(28);签名证书不变。ktv_api.js 未改动,KTV_BRIDGE_API 仍为 8。
This commit is contained in:
zijunchiang
2026-09-26 20:38:52 +08:00
parent a7a28fc45d
commit 906fa210e4
6 changed files with 111 additions and 11 deletions
+18 -1
View File
@@ -160,7 +160,7 @@ $BT/apksigner verify 目标名.apk
### 版本号 ### 版本号
- `app/build.gradle`:`versionName "1.4.7"` / `versionCode 27`(18~21 被本机临时诊断包占用过) - `app/build.gradle`:`versionName "1.4.8"` / `versionCode 28`(18~21 被本机临时诊断包占用过)
- App 内显示统一用纯版本号(不加 `(versionCode)` 括号) - App 内显示统一用纯版本号(不加 `(versionCode)` 括号)
- ⚠️ **发布构建已开启 NewApi 闸门**(`lint { checkReleaseBuilds true; fatal += ['NewApi'] }`): - ⚠️ **发布构建已开启 NewApi 闸门**(`lint { checkReleaseBuilds true; fatal += ['NewApi'] }`):
任何「调用了高于 `minSdk 21` 且未做版本守卫的 API」都会让 `assembleRelease` 直接失败。 任何「调用了高于 `minSdk 21` 且未做版本守卫的 API」都会让 `assembleRelease` 直接失败。
@@ -297,6 +297,23 @@ $BT/apksigner verify 目标名.apk
客户端为 `MiliLog`(有界队列 + 后台线程 + 失败重试),调用点 `MiliLog.info/notice/warn/error` 客户端为 `MiliLog`(有界队列 + 后台线程 + 失败重试),调用点 `MiliLog.info/notice/warn/error`
保持不变。启动上报(`reportDeviceBootInfo()`)只采集这 10 项:包名、版本号、安装时间、品牌、型号、 保持不变。启动上报(`reportDeviceBootInfo()`)只采集这 10 项:包名、版本号、安装时间、品牌、型号、
设备名、Android 版本、CPU 架构、内核版本、屏幕分辨率 设备名、Android 版本、CPU 架构、内核版本、屏幕分辨率
- **写日志的五条约定**(2026-09-26 依据现场日志复盘补充):
1. **持久状态只记一次**,不要每次事件都记。反例:桥不可用曾按「每次点歌一条 WARN」输出,
一台机器一天几百条、把日志刷满且毫无新增信息。现在由 `KtvJsBridge.markUnavailable()`
在**状态首次变化**时记一条。
2. **关键行必须带全上下文**:`STORAGE`/`BOOT` 这类启动行要放在 `reportDeviceBootInfo()` 的
后台线程里、`refreshLogDeviceContext()` 与 `MiliLog.awaitServerIp()` **之后**,
否则 `serverip`/`clientip`/`user`/`traceid` 全是 `undefined`(旧日志按设备检索不到)。
3. **不要在日志行里做重活**:`AppPaths.storageFacts()`/`diagnose()` 会真实建目录、写探针、
读 `/proc/mounts`,**绝不能放在主线程**(启动时曾如此)。
4. **日志要能自我定位**:失败行写清"哪一步/哪个源/耗时/原因",例如
`NATIVE-SONG 全部源失败 编号=... 详情=token-fail|no-url|demo-or-mismatch 用时=...ms`;
桥侧由 `JS-BRIDGE ...` 说明 WebView 到底卡在哪一步(初始化失败/KtvApi 未导出/20s 超时)。
5. **状态样本 + 事件**缺一不可:事件(点歌/失败)说明"发生了什么",但排查"随时间变化"的
问题(空间变少、曲库丢失、长期离线)需要状态样本 —— 现由 6 小时一条 `HEALTH ...`
(版本/在线/可用空间/曲库大小/根目录)提供。
- 一段典型现场日志应为:`BOOT` → `STORAGE` → (点歌)`点歌编号=... 请求源=... 状态=成功 urlHost=...`
→ `PLAY ... src=local` → 每 6h `HEALTH ...`;异常时才有 `RAW-ERR`/`NET-ERR`/`NATIVE-SONG ...失败`。
- **网络状态与断网恢复**:`KtvNetworkMonitor`(object,走 `ConnectivityManager` 回调、不轮询) - **网络状态与断网恢复**:`KtvNetworkMonitor`(object,走 `ConnectivityManager` 回调、不轮询)
维护全局 `online`;`MainActivity.onNetworkStateChanged()` 负责: 维护全局 `online`;`MainActivity.onNetworkStateChanged()` 负责:
- 断网 → 播放页右上角 `fullScreenNetworkBadge` 显示「网络未连接」(在全屏控制层 header 内、 - 断网 → 播放页右上角 `fullScreenNetworkBadge` 显示「网络未连接」(在全屏控制层 header 内、
+2 -2
View File
@@ -11,8 +11,8 @@ android {
applicationId "com.local.ktv" applicationId "com.local.ktv"
minSdk 21 minSdk 21
targetSdk 25 targetSdk 25
versionCode 27 versionCode 28
versionName "1.4.7" versionName "1.4.8"
ndk { ndk {
// 双 ABI 打包:兼容 64 位(Exynos 1580 等 arm64-v8a)与 32 位设备(极米 Play 超越版 // 双 ABI 打包:兼容 64 位(Exynos 1580 等 arm64-v8a)与 32 位设备(极米 Play 超越版
// 的 Amlogic 950X2/S905X2 采用 32 位 Android 用户态,必须包含 armeabi-v7a,否则 // 的 Amlogic 950X2/S905X2 采用 32 位 Android 用户态,必须包含 armeabi-v7a,否则
+43 -2
View File
@@ -45,6 +45,8 @@ class KtvJsBridge(context: Context) {
"https://gitea.kasugano.cn/zijunchiang/maidong-ktv/raw/branch/master/app/src/main/assets/mobile/ktv_api.js" "https://gitea.kasugano.cn/zijunchiang/maidong-ktv/raw/branch/master/app/src/main/assets/mobile/ktv_api.js"
private const val MAX_RESPONSE_BYTES = 2 * 1024 * 1024 private const val MAX_RESPONSE_BYTES = 2 * 1024 * 1024
private const val JS_REQUEST_TIMEOUT_MS = 180_000 private const val JS_REQUEST_TIMEOUT_MS = 180_000
/** WebView 初始化看门狗:超过这个时间还没就绪就判定本机 WebView 不可用。 */
private const val BRIDGE_INIT_TIMEOUT_MS = 20_000L
// 歌曲源(w.w345.my 与 e.ac19.cn 同后台)按 device 识别; 随机/变化的 device 会被风控。 // 歌曲源(w.w345.my 与 e.ac19.cn 同后台)按 device 识别; 随机/变化的 device 会被风控。
// mac 取本机「当前在用网卡」的硬件地址(读不到时回退历史抓包值, 见 DeviceMac); // mac 取本机「当前在用网卡」的硬件地址(读不到时回退历史抓包值, 见 DeviceMac);
// sn 沿用抓包注册值, 保证 mac 变化后仍能对上原有账号体系。 // sn 沿用抓包注册值, 保证 mac 变化后仍能对上原有账号体系。
@@ -75,6 +77,17 @@ class KtvJsBridge(context: Context) {
@Volatile private var webView: WebView? = null @Volatile private var webView: WebView? = null
@Volatile private var ready = false @Volatile private var ready = false
@Volatile private var destroyed = false @Volatile private var destroyed = false
/**
* 已判定「本机 WebView 不可用」。
*
* 一旦置位,`SongApiClient` 就不再为取址白等 15 秒,直接走原生通道
* (极米 H1S 实测每次点歌都要等满 15 秒,日志里表现为每首歌前一条
* 「JS-BRIDGE 15s 未就绪」)。桥万一后来就绪(热更新重载等)会自动清除。
*/
@Volatile private var unavailable = false
private var unavailableReason: String = ""
private var loadedFromCache = false private var loadedFromCache = false
private var assetRetryAttempted = false private var assetRetryAttempted = false
@@ -96,9 +109,17 @@ class KtvJsBridge(context: Context) {
loadedFromCache = cachedScript != null loadedFromCache = cachedScript != null
createWebView(cachedScript ?: readAssetScript(), callback) createWebView(cachedScript ?: readAssetScript(), callback)
updateCache(cached) updateCache(cached)
// 看门狗:onPageFinished 一直不回调(WebView 静默失效)时给出**明确原因**。
// 否则远程日志里只会看到反复的「15s 未就绪」,不知道卡在哪一步。
mainHandler.postDelayed({
if (!ready && !destroyed && !unavailable) {
markUnavailable("初始化超时:onPageFinished 未回调或 KtvApi 未导出")
callback(false)
}
}, BRIDGE_INIT_TIMEOUT_MS)
} catch (error: Throwable) { } catch (error: Throwable) {
Log.e(TAG, "WebView init failed", error) Log.e(TAG, "WebView init failed", error)
MiliLog.error("JS-BRIDGE WebView 初始化失败: ${error.javaClass.simpleName}: ${error.message}") markUnavailable("WebView 初始化失败: ${error.javaClass.simpleName}: ${error.message}")
callback(false) callback(false)
} }
} }
@@ -138,6 +159,12 @@ class KtvJsBridge(context: Context) {
view.evaluateJavascript("typeof window.KtvApi === 'function'") { result -> view.evaluateJavascript("typeof window.KtvApi === 'function'") { result ->
if (result == "true") { if (result == "true") {
ready = true ready = true
// 桥后来就绪(例如热更新重载成功)→ 清除"不可用"标记,恢复 JS 主路径。
if (unavailable) {
unavailable = false
MiliLog.info("JS-BRIDGE 已恢复可用(${unavailableReason.ifEmpty { "?" }} 已解除)")
unavailableReason = ""
}
Log.i(TAG, "JS runtime ready (${if (loadedFromCache) "cache" else "asset"})") Log.i(TAG, "JS runtime ready (${if (loadedFromCache) "cache" else "asset"})")
MiliLog.info("JS-BRIDGE ready (${if (loadedFromCache) "cache" else "asset"})") MiliLog.info("JS-BRIDGE ready (${if (loadedFromCache) "cache" else "asset"})")
callback(true) callback(true)
@@ -150,7 +177,7 @@ class KtvJsBridge(context: Context) {
Log.e(TAG, "KtvApi was not exported by JS") Log.e(TAG, "KtvApi was not exported by JS")
// 老电视盒子上 WebView 不可用/被裁剪时常走这里:桥永远不就绪, // 老电视盒子上 WebView 不可用/被裁剪时常走这里:桥永远不就绪,
// 取址只能回退 DB → 「无法生成下载地址」。必须能远程看到。 // 取址只能回退 DB → 「无法生成下载地址」。必须能远程看到。
MiliLog.error("JS-BRIDGE KtvApi 未导出,WebView 不可用") markUnavailable("KtvApi 未导出")
callback(false) callback(false)
} }
} }
@@ -163,6 +190,20 @@ class KtvJsBridge(context: Context) {
/** 桥当前是否可用。热更新重载期间会短暂为 false,调用方应据此等待而非立即回退。 */ /** 桥当前是否可用。热更新重载期间会短暂为 false,调用方应据此等待而非立即回退。 */
fun isReady(): Boolean = ready && !destroyed fun isReady(): Boolean = ready && !destroyed
/** 是否已判定本机 WebView 不可用(用于跳过必然失败的等待)。 */
fun isUnavailable(): Boolean = unavailable && !destroyed && !ready
/**
* 标记桥在本机不可用。**只在状态首次变化时上报一次**:
* 这是持久状态,若每次点歌都记一条会把远程日志刷满(实测每首歌一条)。
*/
fun markUnavailable(reason: String) {
if (unavailable) return
unavailable = true
unavailableReason = reason
MiliLog.error("JS-BRIDGE 判定本机 WebView 不可用($reason),后续点歌直接走原生取址通道")
}
/** /**
* 供**原生兜底取址解析器**([SongUrlResolver])复用的「干净请求」通道。 * 供**原生兜底取址解析器**([SongUrlResolver])复用的「干净请求」通道。
* *
@@ -187,12 +187,32 @@ class MainActivity : AppCompatActivity() {
} }
/** 周期向 hbeat.ktvsky.com 上报设备身份,维持歌曲源对"合法设备"的判定。 */ /** 周期向 hbeat.ktvsky.com 上报设备身份,维持歌曲源对"合法设备"的判定。 */
private var heartbeatTicks = 0
private val ktvHeartbeatRunnable = object : Runnable { private val ktvHeartbeatRunnable = object : Runnable {
override fun run() { override fun run() {
sendDeviceHeartbeat(boot = false) sendDeviceHeartbeat(boot = false)
// 每 6 小时留一条健康快照:日志此前只有"事件"(点歌/失败/升级),
// 没有"状态样本",现场排查空间/曲库/网络随时间的变化时缺参照。
heartbeatTicks++
if (heartbeatTicks % 6 == 0) logHealthSnapshot()
main.postDelayed(this, HEARTBEAT_INTERVAL_MS) main.postDelayed(this, HEARTBEAT_INTERVAL_MS)
} }
} }
/** 健康快照:版本 / 在线 / 可用空间 / 曲库文件 —— 单行,便于按 HEALTH 检索。 */
private fun logHealthSnapshot() {
runCatching {
val db = AppPaths.databaseFile
val freeGb = AppPaths.databaseDir.usableSpace / 1024.0 / 1024.0 / 1024.0
MiliLog.notice(
"HEALTH ver=${BuildConfig.VERSION_NAME} online=${KtvNetworkMonitor.online}" +
" free=${String.format(Locale.ROOT, "%.2f", freeGb)}GB" +
" dbExist=${db.exists()} dbMB=${db.length() / 1024 / 1024}" +
" root=${AppPaths.root.absolutePath}",
)
}
}
private val visibleSongs: MutableList<Song> = ArrayList<Song>() private val visibleSongs: MutableList<Song> = ArrayList<Song>()
private val visibleSingers: MutableList<Array<String?>?> = ArrayList<Array<String?>?>() private val visibleSingers: MutableList<Array<String?>?> = ArrayList<Array<String?>?>()
private val visiblePlaylists: MutableList<Array<String?>> = ArrayList() private val visiblePlaylists: MutableList<Array<String?>> = ArrayList()
@@ -470,8 +490,10 @@ class MainActivity : AppCompatActivity() {
playbackEngine = KtvPlaybackEngine(applicationContext) playbackEngine = KtvPlaybackEngine(applicationContext)
// 远程日志系统(GlogCenter): 启动即上报设备/网络信息。 // 远程日志系统(GlogCenter): 启动即上报设备/网络信息。
MiliLog.init(applicationContext) MiliLog.init(applicationContext)
// 存储根目录探测结果(排查不同盒子存储差异用;单行便于按 STORAGE 检索)。 // ⚠️ STORAGE 探测含真实建目录/写盘与 /proc/mounts 读取,**不能放在主线程**,
MiliLog.info("STORAGE ${AppPaths.storageFacts(this)}") // 而且必须在 refreshLogDeviceContext() 之后,否则这一行的
// serverip/clientip/user/traceid 全是 undefined(旧日志就是这样,无法按设备检索)。
// 现在统一在 reportDeviceBootInfo() 的后台线程里、awaitServerIp() 之后上报。
refreshLogDeviceContext() refreshLogDeviceContext()
reportDeviceBootInfo() reportDeviceBootInfo()
// 歌曲源窗口/风控到期守卫: 源对陌生出口 IP 可能在短暂窗口后返回 403, // 歌曲源窗口/风控到期守卫: 源对陌生出口 IP 可能在短暂窗口后返回 403,
@@ -3725,6 +3747,9 @@ class MainActivity : AppCompatActivity() {
// 等主机 IP(公网出口 IP)就绪,避免启动这条日志的 serverip 为空。 // 等主机 IP(公网出口 IP)就绪,避免启动这条日志的 serverip 为空。
MiliLog.awaitServerIp() MiliLog.awaitServerIp()
MiliLog.notice(sb.toString()) MiliLog.notice(sb.toString())
// 存储根目录探测结果(排查不同盒子存储差异用;单行便于按 STORAGE 检索)。
// 放在这里而不是启动主线程:既有完整上下文,又避免了主线程磁盘探测。
runCatching { MiliLog.notice("STORAGE ${AppPaths.storageFacts(this@MainActivity)}") }
} catch (ignored: Exception) { } catch (ignored: Exception) {
} }
}, "ktv-boot-log").start() }, "ktv-boot-log").start()
@@ -55,6 +55,11 @@ object SongApiClient {
return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno) return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno)
} }
val bridge = bridge ?: return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno) val bridge = bridge ?: return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno)
// 已判定本机 WebView 不可用 → 不再每次白等 15 秒,直接用原生通道。
// (极米 H1S 实测:每次都等满 15 秒,远程日志里每首歌前都有一条「15s 未就绪」。)
if (bridge.isUnavailable()) {
return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno)
}
// 等待 JS 桥"当前"真正就绪。首次冷启动时隐藏 WebView 的初始化在低性能设备 // 等待 JS 桥"当前"真正就绪。首次冷启动时隐藏 WebView 的初始化在低性能设备
// (极米投影等)上可能超过 3 秒;桥热更新重载期间 isReady() 也会短暂为 false。 // (极米投影等)上可能超过 3 秒;桥热更新重载期间 isReady() 也会短暂为 false。
// 这里放宽到 15 秒,避免第一首歌因撞上就绪窗口而回退到不可靠的 DB cloud_url。 // 这里放宽到 15 秒,避免第一首歌因撞上就绪窗口而回退到不可靠的 DB cloud_url。
@@ -67,9 +72,10 @@ object SongApiClient {
} }
if (!bridge.isReady()) { if (!bridge.isReady()) {
// ⚠️ 老盒子(WebView 不可用)会一直走到这里。以前直接回退 DB,结果就是 // ⚠️ 老盒子(WebView 不可用)会一直走到这里。以前直接回退 DB,结果就是
// 「无法生成下载地址」且远程日志里连一条 JS 日志都没有。现在改走原生解析器。 // 「无法生成下载地址」且远程日志里连一条 JS 日志都没有。现在改走原生解析器,
// 并把"不可用"记成持久状态(只上报一次),后续点歌不再等这 15 秒。
Log.w(TAG, "Bridge not ready after wait, native resolver") Log.w(TAG, "Bridge not ready after wait, native resolver")
MiliLog.warn("JS-BRIDGE 15s 未就绪,改用原生取址通道") bridge.markUnavailable("15s 未就绪")
return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno) return resolveNatively(musicno, resolution, h265) ?: fetchFromDb(musicno)
} }
val result = AtomicReference<String?>() val result = AtomicReference<String?>()
@@ -140,7 +146,8 @@ object SongApiClient {
bridge?.resetApiSession() bridge?.resetApiSession()
} }
/** 最近一次点歌实际命中的歌曲源 host(由 JS 上报, 用于远程日志)。 */ /** 最近一次取址命中的源:优先 JS 上报,其次原生兜底记录(供远程日志的「请求源=」)。 */
@JvmStatic @JvmStatic
fun lastSongSourceHost(): String = bridge?.lastSongSourceHost.orEmpty() fun lastSongSourceHost(): String =
bridge?.lastSongSourceHost?.takeIf { it.isNotEmpty() } ?: SongUrlResolver.lastHost
} }
@@ -56,6 +56,15 @@ object SongUrlResolver {
@Volatile private var sn: String = KtvJsBridge.DEVICE_SN @Volatile private var sn: String = KtvJsBridge.DEVICE_SN
/**
* 最近一次取址命中的源 host。
* 供 `SongApiClient.lastSongSourceHost()` 使用 —— 走原生兜底时 JS 的
* `reportSongResult` 不会触发,否则日志里「请求源=」永远是空的。
*/
@Volatile
var lastHost: String = ""
private set
/** /**
* 安装取址通道。 * 安装取址通道。
* @param fetch 干净的 HTTP GET(应传 [KtvJsBridge.rawCleanGet]); * @param fetch 干净的 HTTP GET(应传 [KtvJsBridge.rawCleanGet]);
@@ -115,6 +124,7 @@ object SongUrlResolver {
} }
if (!url.isNullOrEmpty() && isValidSongUrl(url, musicno)) { if (!url.isNullOrEmpty() && isValidSongUrl(url, musicno)) {
promote(host) promote(host)
lastHost = host
val elapsed = System.currentTimeMillis() - startedAt val elapsed = System.currentTimeMillis() - startedAt
val urlHost = runCatching { java.net.URI(url).host }.getOrNull() ?: "?" val urlHost = runCatching { java.net.URI(url).host }.getOrNull() ?: "?"
MiliLog.info( MiliLog.info(