add subtitle pipeline proof logging

This commit is contained in:
dirtydishes 2026-05-25 10:07:28 -04:00
parent fdc4444f6a
commit d8ebc7c7f9
7 changed files with 473 additions and 7 deletions

View file

@ -127,6 +127,7 @@ final class DreamioWebViewController: UIViewController {
};
const postSubtitleCandidates = (candidates) => {
const discoveredCount = candidates.length;
const fresh = candidates.filter((candidate) => {
if (postedSubtitleURLs.has(candidate.url)) {
return false;
@ -135,12 +136,28 @@ final class DreamioWebViewController: UIViewController {
return true;
});
if (fresh.length === 0) {
try {
window.webkit.messageHandlers.dreamioSubtitleCandidate.postMessage({
pageUrl: window.location.href,
subtitles: [],
debug: {
discovered: discoveredCount,
deduped: 0,
forwarded: 0
}
});
} catch (_) {}
return;
}
try {
window.webkit.messageHandlers.dreamioSubtitleCandidate.postMessage({
pageUrl: window.location.href,
subtitles: fresh
subtitles: fresh,
debug: {
discovered: discoveredCount,
deduped: fresh.length,
forwarded: fresh.length
}
});
} catch (_) {}
};
@ -480,6 +497,9 @@ final class DreamioWebViewController: UIViewController {
return
}
#if DEBUG
print("[DreamioSubtitles] native discovered=\(candidates.count) playerActive=\(currentNativePlayer != nil) candidates=\(SubtitleDebugFormatter.candidateSummary(candidates))")
#endif
guard let currentNativePlayer else {
#if DEBUG
print("[DreamioSubtitles] discovered=\(candidates.count) forwarded=0 reason=no-active-native-player")
@ -489,7 +509,7 @@ final class DreamioWebViewController: UIViewController {
let forwarded = currentNativePlayer.addSubtitleCandidates(candidates)
#if DEBUG
print("[DreamioSubtitles] discovered=\(candidates.count) forwarded=\(forwarded)")
print("[DreamioSubtitles] discovered=\(candidates.count) forwarded=\(forwarded) reason=active-native-player")
#endif
}
@ -658,6 +678,16 @@ final class DreamioWebViewController: UIViewController {
private func redactedURLString(_ value: String) -> String {
URLRedactor.redactedURLString(value)
}
private func logSubtitleBridgeMessage(_ body: Any, parsedCandidates: [SubtitleCandidate]) {
let dictionary = body as? [String: Any]
let debug = dictionary?["debug"] as? [String: Any]
let discovered = debug?["discovered"] as? Int ?? parsedCandidates.count
let deduped = debug?["deduped"] as? Int ?? parsedCandidates.count
let posted = debug?["forwarded"] as? Int ?? parsedCandidates.count
let pageURL = dictionary?["pageUrl"] as? String
print("[DreamioSubtitles] bridge discovered=\(discovered) deduped=\(deduped) posted=\(posted) parsed=\(parsedCandidates.count) playerActive=\(currentNativePlayer != nil) page=\(pageURL.map(redactedURLString) ?? "unknown") candidates=\(SubtitleDebugFormatter.candidateSummary(parsedCandidates))")
}
#endif
}
@ -735,7 +765,11 @@ extension DreamioWebViewController: WKScriptMessageHandler {
}
if message.name == Constants.subtitleCandidateMessageHandler {
handleSubtitleCandidates(SubtitleCandidateParser.candidates(in: message.body))
let candidates = SubtitleCandidateParser.candidates(in: message.body)
#if DEBUG
logSubtitleBridgeMessage(message.body, parsedCandidates: candidates)
#endif
handleSubtitleCandidates(candidates)
return
}

View file

@ -140,7 +140,7 @@ final class NativePlayerViewController: UIViewController {
let pendingCandidates = candidates.filter { !attachedSubtitleURLs.contains($0.url) }
guard !pendingCandidates.isEmpty else {
#if DEBUG
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=0 duplicates=\(candidates.count)")
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=0 duplicates=\(candidates.count) resolved=0 attached=0 tracks=\(SubtitleDebugFormatter.trackSummary(backend.subtitleTracks)) selected=\(backend.selectedSubtitleTrackID)")
#endif
return 0
}
@ -155,7 +155,7 @@ final class NativePlayerViewController: UIViewController {
await MainActor.run {
guard !resolvedCandidates.isEmpty else {
#if DEBUG
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=\(pendingCandidates.count) resolved=0 attached=0")
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=\(pendingCandidates.count) resolved=0 attached=0 tracks=\(SubtitleDebugFormatter.trackSummary(self.backend.subtitleTracks)) selected=\(self.backend.selectedSubtitleTrackID) candidates=\(SubtitleDebugFormatter.candidateSummary(pendingCandidates))")
#endif
return
}
@ -172,7 +172,7 @@ final class NativePlayerViewController: UIViewController {
}
#if DEBUG
let duplicateCount = candidates.count - pendingCandidates.count + resolvedCandidates.count - attachableCandidates.count
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=\(pendingCandidates.count) resolved=\(resolvedCandidates.count) attached=\(attachedCount) duplicates=\(duplicateCount)")
print("[DreamioNativePlayer] subtitle candidates=\(candidates.count) pending=\(pendingCandidates.count) resolved=\(resolvedCandidates.count) attachable=\(attachableCandidates.count) attached=\(attachedCount) duplicates=\(duplicateCount) tracks=\(SubtitleDebugFormatter.trackSummary(self.backend.subtitleTracks)) selected=\(self.backend.selectedSubtitleTrackID) resolvedCandidates=\(SubtitleDebugFormatter.candidateSummary(resolvedCandidates))")
#endif
}
}

View file

@ -40,6 +40,33 @@ struct SubtitleTrack: Equatable {
let name: String
}
#if DEBUG
enum SubtitleDebugFormatter {
static func candidateSummary(_ candidates: [SubtitleCandidate]) -> String {
guard !candidates.isEmpty else {
return "[]"
}
return candidates.map { candidate in
let extensionLabel = candidate.url.pathExtension.isEmpty ? "none" : candidate.url.pathExtension.lowercased()
let language = candidate.language?.isEmpty == false ? candidate.language! : "unknown"
let label = candidate.label.isEmpty ? "External Subtitle" : candidate.label
return "{label=\(label), language=\(language), ext=\(extensionLabel)}"
}.joined(separator: ", ")
}
static func trackSummary(_ tracks: [SubtitleTrack]) -> String {
guard !tracks.isEmpty else {
return "[]"
}
return tracks.map { track in
"{id=\(track.id), name=\(track.name)}"
}.joined(separator: ", ")
}
}
#endif
enum PlaybackTimeFormatter {
static func label(for seconds: TimeInterval) -> String {
guard seconds.isFinite, seconds > 0 else {

View file

@ -214,7 +214,8 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
mediaPlayer.addPlaybackSlave(candidate.url, type: .subtitle, enforce: false)
attachedCount += 1
#if DEBUG
print("[DreamioVLC] attached subtitle=\(URLRedactor.redactedURLString(candidate.url.absoluteString))")
print("[DreamioVLC] addPlaybackSlave subtitle=\(URLRedactor.redactedURLString(candidate.url.absoluteString)) label=\(candidate.label) language=\(candidate.language ?? "unknown") ext=\(candidate.url.pathExtension.lowercased())")
logSubtitleTracks(reason: "after-addPlaybackSlave")
#endif
}
#if DEBUG
@ -226,10 +227,21 @@ final class VLCNativePlaybackBackend: NSObject, NativePlaybackBackend {
return attachedCount
}
DispatchQueue.main.asyncAfter(deadline: .now() + 1) { [weak self] in
#if DEBUG
self?.logSubtitleTracks(reason: "delayed-refresh")
#endif
self?.onSubtitleTracksChange?()
}
return attachedCount
}
#if DEBUG
private func logSubtitleTracks(reason: String) {
let names = mediaPlayer.videoSubTitlesNames as? [String] ?? []
let indexes = mediaPlayer.videoSubTitlesIndexes as? [NSNumber] ?? []
print("[DreamioVLC] subtitle tracks reason=\(reason) names=\(names) indexes=\(indexes.map { $0.int32Value }) selected=\(mediaPlayer.currentVideoSubTitleIndex)")
}
#endif
#endif
}
@ -248,6 +260,9 @@ extension VLCNativePlaybackBackend: VLCMediaPlayerDelegate {
case .paused, .stopped, .ended:
onStateChange?()
case .esAdded:
#if DEBUG
logSubtitleTracks(reason: "esAdded")
#endif
onSubtitleTracksChange?()
default:
break