From ea0920e4e350694a434abd898526a3d3ee4e9005 Mon Sep 17 00:00:00 2001 From: Yuyi-Oak <1722157266@qq.com> Date: Tue, 7 Jul 2026 22:13:07 +0800 Subject: [PATCH] feat: add official sync progress logging --- CURRENT_STATUS.md | 2 +- README.md | 2 + .../architecture/official-resource-backend.md | 2 +- docs/guides/deployment.md | 2 +- docs/guides/official-resource-test-pull.md | 2 +- infrastructure/src/bin/bat_official_sync.rs | 98 ++++- infrastructure/src/lib.rs | 9 +- infrastructure/src/official_download.rs | 146 ++++++- infrastructure/src/official_update.rs | 361 +++++++++++++++++- .../official_game_main_config_bootstrap.rs | 36 +- 10 files changed, 639 insertions(+), 21 deletions(-) diff --git a/CURRENT_STATUS.md b/CURRENT_STATUS.md index ddf47cb..8c7f2de 100644 --- a/CURRENT_STATUS.md +++ b/CURRENT_STATUS.md @@ -20,7 +20,7 @@ Rust 侧官方日服资源链路已经从实验验证推进到正式入口： 4. 能生成官方全量 pull plan，执行真实下载，维护 `official-download-manifest.json`。 5. 下载后使用本地 manifest 的 size + BLAKE3 校验复用文件；官方 seed `.hash` 使用 `xxHash32(seed=0)` 强校验。 6. 支持 `.part` 断点续传、失败后 clean retry、本地 manifest audit/repair。 -7. `bat-official-sync --watch` 可常驻运行，正常检查默认每 1 小时一次；远端和本地一致时默认静默，失败后默认 60 秒快速重试。 +7. `bat-official-sync --watch` 可常驻运行，正常检查默认每 1 小时一次；远端和本地一致时默认静默，失败后默认 60 秒快速重试；CLI 默认向 stderr 输出人类可读 progress log。 8. 非 dry-run 使用 `--output/.official-sync.lock` 防止并发写同一状态目录。 仍需明确：这不是完整产品完成。Go CLI 最小入口、完整 AssetBundle 解析、Patch、翻译系统、API Server 和 Web 仍是后续工作；真实官方网络全量下载 smoke test 尚未记录在仓库文档中。 diff --git a/README.md b/README.md index cf5506c..9d2bb9c 100644 --- a/README.md +++ b/README.md @@ -82,6 +82,8 @@ cargo run -p bat-infrastructure --bin bat-official-sync -- \ --error-retry 60s ``` +CLI 默认会把人类可读的阶段进度日志写到 stderr，例如自动发现、拉取 catalog、audit、下载第 N/总数个 URL 等；成功后的稳定 JSON report 仍写到 stdout。需要给上层程序保留纯机器输出时可加 `--no-progress`。 + 生产输出目录必须使用独立状态目录，不要指向已有客户端目录，也不要指向 `/home/wanye/D/BlueArchive` 这类人工维护或开发资源目录。 --- diff --git a/docs/architecture/official-resource-backend.md b/docs/architecture/official-resource-backend.md index 840ad83..fafe961 100644 --- a/docs/architecture/official-resource-backend.md +++ b/docs/architecture/official-resource-backend.md @@ -228,7 +228,7 @@ Linux 生产路径： - pull plan 会同时包含 discovery URLs 和 content URLs - 全量样本下是 `2` 个 discovery URL + `5` 个内容 URL = `7` 个 URL - `OfficialUpdateService` 能持久化 v2 snapshot，并在远端 marker 内容变化时触发下载决策 -- `bat-official-sync` 输出稳定 JSON report，支持 `--watch --interval 1h --error-retry 60s` 常驻运行，非 dry-run 使用 `.official-sync.lock` 防止并发写状态目录 +- `bat-official-sync` 默认向 stderr 输出人类可读 progress log，成功 JSON report 保持 stdout；支持 `--no-progress` 关闭进度日志，支持 `--watch --interval 1h --error-retry 60s` 常驻运行，非 dry-run 使用 `.official-sync.lock` 防止并发写状态目录 - `OfficialUpdateService` 能读写 `official-bootstrap-cache.json`，并支持默认开启的 `audit_local` / `repair` CLI 行为 - 下载层能在本地文件 size/BLAKE3/path 或 manifest 不匹配时重新下载 - 官方 seed `.hash` mismatch 会导致下载失败，而不是降级为本地 BLAKE3 猜测 diff --git a/docs/guides/deployment.md b/docs/guides/deployment.md index ccd53ea..8a57e2d 100644 --- a/docs/guides/deployment.md +++ b/docs/guides/deployment.md @@ -157,7 +157,7 @@ target/release/bat-official-sync --watch ``` -`--watch` 是 Rust 内部持久检查模式，正常情况下默认每 1 小时执行一次检查。远端和本地一致时默认静默；有远端变化或本地文件损坏时自动下载或 repair，并输出 JSON report。下载、发现或校验失败时默认 60 秒后重试，可显式加 `--error-retry 60s` 或 `--error-retry-seconds 60` 调整。 +`--watch` 是 Rust 内部持久检查模式，正常情况下默认每 1 小时执行一次检查。远端和本地一致时默认静默；有远端变化或本地文件损坏时自动下载或 repair，并输出 JSON report。下载、发现或校验失败时默认 60 秒后重试，可显式加 `--error-retry 60s` 或 `--error-retry-seconds 60` 调整。默认进度日志写到 stderr，成功 JSON report 写到 stdout；如果由上层服务严格解析 stderr/stdout，可加 `--no-progress`。 ### systemd service 示例 diff --git a/docs/guides/official-resource-test-pull.md b/docs/guides/official-resource-test-pull.md index 1fdce90..42faaba 100644 --- a/docs/guides/official-resource-test-pull.md +++ b/docs/guides/official-resource-test-pull.md @@ -229,7 +229,7 @@ cargo run -p bat-infrastructure --bin bat-official-sync -- \ --error-retry 60s ``` -`--interval` 是正常检查周期，默认 `1h`；`--error-retry` 是下载、发现或校验失败后的重试周期，默认 `60s`，也可以用 `--error-retry-seconds 60`。命令成功时 stdout 输出稳定 JSON report；错误时 stderr 输出 JSON error，watch 模式下错误 JSON 的 `next_retry_seconds` 使用失败重试周期。普通错误 exit `1`，状态目录锁冲突 exit `75`。 +`--interval` 是正常检查周期，默认 `1h`；`--error-retry` 是下载、发现或校验失败后的重试周期，默认 `60s`，也可以用 `--error-retry-seconds 60`。CLI 默认把人类可读的阶段进度日志写到 stderr，包括自动发现、server-info、marker、catalog、audit、download 和 snapshot 阶段；成功时 stdout 输出稳定 JSON report。需要纯机器输出时加 `--no-progress`，需要显式开启则用 `--progress`。错误时 stderr 输出 JSON error，watch 模式下错误 JSON 的 `next_retry_seconds` 使用失败重试周期；如果未关闭 progress，错误 JSON 前可能已有进度日志。普通错误 exit `1`，状态目录锁冲突 exit `75`。 生产可以直接运行 `--watch`，也可以用 systemd service、容器或 Go 进程守护它。cron/systemd timer 仍可调用单次模式，但不再是 Rust 自动更新的唯一方式。项目是否热更新、热重载或重启进程，由上层业务集成决定。生产目录应使用独立输出目录，不要指向现有客户端或人工维护的资源目录。非 dry-run 每轮会创建 `--output/.official-sync.lock`，防止并发写同一状态目录。 diff --git a/infrastructure/src/bin/bat_official_sync.rs b/infrastructure/src/bin/bat_official_sync.rs index 9921ec4..39454b2 100644 --- a/infrastructure/src/bin/bat_official_sync.rs +++ b/infrastructure/src/bin/bat_official_sync.rs @@ -1,12 +1,13 @@ use bat_adapters::official::yostar_jp::PatchPlatform; use bat_infrastructure::{ - OfficialServerInfoSource, OfficialUpdateConfig, OfficialUpdateService, OfficialUpdateStatus, + OfficialServerInfoSource, OfficialUpdateConfig, OfficialUpdateProgress, OfficialUpdateService, + OfficialUpdateStatus, }; use serde::Serialize; use std::env; use std::path::PathBuf; use std::thread; -use std::time::Duration; +use std::time::{Duration, Instant}; const EXIT_ERROR: i32 = 1; const EXIT_LOCKED: i32 = 75; @@ -43,7 +44,10 @@ fn run() -> anyhow::Result<()> { if options.watch { run_watch(options)?; } else { - let report = OfficialUpdateService::new().run(&options.config)?; + let mut logger = ProgressLogger::new(options.progress); + let report = OfficialUpdateService::new().run_with_progress(&options.config, |event| { + logger.log(event); + })?; if should_print_status(report.update_status, options.quiet_up_to_date) { println!("{}", serde_json::to_string_pretty(&report)?); } @@ -68,6 +72,7 @@ struct CliOptions { error_retry_interval: Duration, quiet_up_to_date: bool, quiet_up_to_date_explicit: bool, + progress: bool, } impl Default for CliOptions { @@ -79,6 +84,7 @@ impl Default for CliOptions { error_retry_interval: Duration::from_secs(DEFAULT_ERROR_RETRY_SECONDS), quiet_up_to_date: false, quiet_up_to_date_explicit: false, + progress: true, } } } @@ -96,16 +102,34 @@ fn run_watch(options: CliOptions) -> anyhow::Result<()> { )); } let service = OfficialUpdateService::new(); + let mut logger = ProgressLogger::new(options.progress); loop { let mut sleep_for = options.interval; - match service.run(&options.config) { + logger.log_text("watch", "starting watch iteration"); + match service.run_with_progress(&options.config, |event| logger.log(event)) { Ok(report) => { if should_print_status(report.update_status, options.quiet_up_to_date) { println!("{}", serde_json::to_string_pretty(&report)?); } + logger.log_text( + "watch", + format!( + "iteration finished with status={}; next check in {}", + report.update_status.as_str(), + format_duration(sleep_for) + ), + ); } Err(error) => { sleep_for = options.error_retry_interval; + logger.log_text( + "watch", + format!( + "iteration failed; retrying in {}: {}", + format_duration(sleep_for), + error + ), + ); let payload = ErrorReport { status: "error", exit_code: EXIT_ERROR, @@ -120,6 +144,37 @@ fn run_watch(options: CliOptions) -> anyhow::Result<()> { } } +#[derive(Debug, Clone)] +struct ProgressLogger { + enabled: bool, + started_at: Instant, +} + +impl ProgressLogger { + fn new(enabled: bool) -> Self { + Self { + enabled, + started_at: Instant::now(), + } + } + + fn log(&mut self, event: OfficialUpdateProgress) { + self.log_text(event.stage, event.message); + } + + fn log_text(&mut self, stage: &str, message: impl AsRef) { + if !self.enabled { + return; + } + eprintln!( + "[+{} INFO] [{}] {}", + format_duration(self.started_at.elapsed()), + stage, + message.as_ref() + ); + } +} + fn should_print_status(status: OfficialUpdateStatus, quiet_up_to_date: bool) -> bool { !(quiet_up_to_date && status == OfficialUpdateStatus::UpToDate) } @@ -233,6 +288,12 @@ fn parse_args_from(raw_args: impl IntoIterator) -> anyhow::Result options.quiet_up_to_date = false; options.quiet_up_to_date_explicit = true; } + "--progress" => { + options.progress = true; + } + "--no-progress" => { + options.progress = false; + } "--help" | "-h" => { print_usage(&binary); std::process::exit(0); @@ -273,7 +334,7 @@ fn print_usage(binary: &str) { [--app-version 1.70.0] [--connection-group ] [--launcher-version 1.7.2] \ [--platforms Windows,Android] [--output official_update_output] [--snapshot official-sync-snapshot.json] \ [--curl curl] [--unzip unzip] [--dry-run] [--plan] [--force] [--audit-local|--no-audit-local] [--repair|--no-repair] \ - [--watch] [--interval 1h|60m|3600s] [--error-retry 60s] [--quiet-up-to-date|--no-quiet-up-to-date]" + [--watch] [--interval 1h|60m|3600s] [--error-retry 60s] [--quiet-up-to-date|--no-quiet-up-to-date] [--progress|--no-progress]" ); } @@ -304,6 +365,14 @@ fn parse_duration(value: &str) -> anyhow::Result { Ok(Duration::from_secs(amount.saturating_mul(multiplier))) } +fn format_duration(duration: Duration) -> String { + let total_millis = duration.as_millis(); + let minutes = total_millis / 60_000; + let seconds = (total_millis / 1_000) % 60; + let millis = total_millis % 1_000; + format!("{minutes:02}:{seconds:02}.{millis:03}") +} + fn parse_platforms(value: &str) -> Result, String> { value .split(',') @@ -368,6 +437,7 @@ mod tests { ); assert!(!options.quiet_up_to_date); assert!(!options.quiet_up_to_date_explicit); + assert!(options.progress); } #[test] @@ -446,6 +516,18 @@ mod tests { assert_eq!(options.error_retry_interval, Duration::from_secs(30)); } + #[test] + fn parses_progress_flags() { + let options = parse(&["bat-official-sync"]).unwrap(); + assert!(options.progress); + + let options = parse(&["bat-official-sync", "--no-progress"]).unwrap(); + assert!(!options.progress); + + let options = parse(&["bat-official-sync", "--no-progress", "--progress"]).unwrap(); + assert!(options.progress); + } + #[test] fn explicit_no_quiet_up_to_date_overrides_watch_default() { let options = parse(&[ @@ -485,6 +567,12 @@ mod tests { assert_eq!(parse_duration("3600").unwrap(), Duration::from_secs(3600)); } + #[test] + fn formats_progress_durations() { + assert_eq!(format_duration(Duration::from_millis(7)), "00:00.007"); + assert_eq!(format_duration(Duration::from_millis(65_432)), "01:05.432"); + } + #[test] fn quiet_up_to_date_suppresses_only_clean_reports() { assert!(!should_print_status(OfficialUpdateStatus::UpToDate, true)); diff --git a/infrastructure/src/lib.rs b/infrastructure/src/lib.rs index 103abd6..5c871ab 100644 --- a/infrastructure/src/lib.rs +++ b/infrastructure/src/lib.rs @@ -24,8 +24,9 @@ pub use cas::FileSystemCasRepository; pub use import::{BundleSource, ImportedResource, ResourceImportReport, ResourceImportService}; pub use official_download::{ OfficialLocalManifestAuditItem, OfficialLocalManifestAuditReport, - OfficialLocalManifestAuditStatus, OfficialResourcePullItem, OfficialResourcePullReport, - OfficialResourcePullService, + OfficialLocalManifestAuditStatus, OfficialResourcePullItem, OfficialResourcePullProgress, + OfficialResourcePullProgressKind, OfficialResourcePullReport, OfficialResourcePullService, + OfficialResourcePullStatus, }; pub use official_game_main_config::OfficialGameMainConfigBootstrapService; pub use official_launcher::{ @@ -47,8 +48,8 @@ pub use official_update::{ read_snapshot, write_bootstrap_cache, write_snapshot, ExtendedSnapshotDelta, GameMainConfigSnapshot, LauncherMetadataSnapshot, OfficialBootstrapCache, OfficialEndpointMarkerRole, OfficialEndpointMarkerSnapshot, OfficialServerInfoSource, - OfficialUpdateConfig, OfficialUpdateReport, OfficialUpdateService, OfficialUpdateSnapshot, - OfficialUpdateStatus, ResolvedBootstrap, + OfficialUpdateConfig, OfficialUpdateProgress, OfficialUpdateReport, OfficialUpdateService, + OfficialUpdateSnapshot, OfficialUpdateStatus, ResolvedBootstrap, }; pub use resources::{InMemoryResourceRepository, SqliteResourceRepository}; diff --git a/infrastructure/src/official_download.rs b/infrastructure/src/official_download.rs index 40eba45..0bd5994 100644 --- a/infrastructure/src/official_download.rs +++ b/infrastructure/src/official_download.rs @@ -24,6 +24,88 @@ pub enum OfficialResourcePullStatus { Downloaded, } +impl OfficialResourcePullStatus { + /// Returns a stable label for reports and progress logs. + pub fn as_str(self) -> &'static str { + match self { + Self::SkippedExisting => "skipped_existing", + Self::Resumed => "resumed", + Self::Downloaded => "downloaded", + } + } +} + +/// Progress event kind emitted while executing an official pull plan. +#[derive(Debug, Clone, Copy, PartialEq, Eq)] +pub enum OfficialResourcePullProgressKind { + /// A URL is about to be checked or downloaded. + Started, + /// A URL finished as skipped, resumed, or downloaded. + Finished, +} + +impl OfficialResourcePullProgressKind { + /// Returns a stable label for progress logs. + pub fn as_str(self) -> &'static str { + match self { + Self::Started => "started", + Self::Finished => "finished", + } + } +} + +/// Progress for one URL in an official pull plan. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct OfficialResourcePullProgress { + /// Progress event kind. + pub kind: OfficialResourcePullProgressKind, + /// One-based URL index in the pull plan. + pub index: usize, + /// Total URL count in the pull plan. + pub total: usize, + /// Official URL currently being processed. + pub url: String, + /// Finished pull status, when `kind` is `Finished`. + pub status: Option, + /// Final local file size, when `kind` is `Finished`. + pub bytes: Option, + /// Bytes transferred during this run, when `kind` is `Finished`. + pub transferred_bytes: Option, +} + +impl OfficialResourcePullProgress { + fn started(index: usize, total: usize, url: String) -> Self { + Self { + kind: OfficialResourcePullProgressKind::Started, + index, + total, + url, + status: None, + bytes: None, + transferred_bytes: None, + } + } + + fn finished( + index: usize, + total: usize, + url: String, + status: OfficialResourcePullStatus, + bytes: u64, + transferred_bytes: u64, + ) -> Self { + Self { + kind: OfficialResourcePullProgressKind::Finished, + index, + total, + url, + status: Some(status), + bytes: Some(bytes), + transferred_bytes: Some(transferred_bytes), + } + } +} + /// Official hash algorithm used by a verified resource sidecar. #[derive(Debug, Clone, Copy, PartialEq, Eq)] pub enum OfficialResourceHashAlgorithm { @@ -240,6 +322,16 @@ impl OfficialResourcePullService { pub fn pull( &self, plan: &OfficialResourcePullPlan, + ) -> Result { + self.pull_with_progress(plan, |_| {}) + } + + /// Executes the plan and calls `progress` for every URL before and after it + /// is checked or downloaded. + pub fn pull_with_progress( + &self, + plan: &OfficialResourcePullPlan, + mut progress: impl FnMut(OfficialResourcePullProgress), ) -> Result { fs::create_dir_all(&self.output_root).map_err(|error| { format!( @@ -251,8 +343,17 @@ impl OfficialResourcePullService { let official_hash_pairs = official_seed_hash_pairs(plan); let force_refresh_urls = official_hash_refresh_urls(&official_hash_pairs); let mut manifest = self.read_download_manifest()?; + let urls = plan.all_urls()?; + let total = urls.len(); let mut items = Vec::new(); - for url in plan.all_urls()? { + for (offset, url) in urls.into_iter().enumerate() { + let index = offset + 1; + progress(OfficialResourcePullProgress::started( + index, + total, + url.clone(), + )); + if !is_official_yostar_jp_url(&url) { return Err(format!("Refusing to download non-official URL: {url}")); } @@ -282,6 +383,14 @@ impl OfficialResourcePullService { result }; + progress(OfficialResourcePullProgress::finished( + index, + total, + url.clone(), + result.status, + result.bytes, + result.transferred_bytes, + )); items.push(OfficialResourcePullItem { url, destination, @@ -1610,6 +1719,41 @@ fi assert!(manifest.entries.contains_key(&report.items[0].url)); } + #[test] + fn pull_emits_started_and_finished_progress_events() { + let out_dir = TempDir::new().unwrap(); + let bin_dir = TempDir::new().unwrap(); + let curl_path = bin_dir.path().join("curl"); + write_fake_curl(&curl_path); + + let service = OfficialResourcePullService::with_curl_command(out_dir.path(), &curl_path); + let plan = build_official_pull_plan_for_platforms( + discovery_plan(), + inventory(), + &[PatchPlatform::Windows], + ); + let expected_urls = plan.all_urls().unwrap().len(); + let mut events = Vec::new(); + + let report = service + .pull_with_progress(&plan, |event| events.push(event)) + .unwrap(); + + assert_eq!(report.items.len(), expected_urls); + assert_eq!(events.len(), expected_urls * 2); + assert_eq!(events[0].kind, OfficialResourcePullProgressKind::Started); + assert_eq!(events[0].index, 1); + assert_eq!(events[0].total, expected_urls); + assert_eq!(events[1].kind, OfficialResourcePullProgressKind::Finished); + assert_eq!( + events[1].status, + Some(OfficialResourcePullStatus::Downloaded) + ); + assert!(events + .iter() + .any(|event| event.url.ends_with("/TableBundles/ExcelDB.db"))); + } + #[test] fn retries_transient_download_failures() { let out_dir = TempDir::new().unwrap(); diff --git a/infrastructure/src/official_update.rs b/infrastructure/src/official_update.rs index 0b78601..3e4223a 100644 --- a/infrastructure/src/official_update.rs +++ b/infrastructure/src/official_update.rs @@ -8,8 +8,9 @@ use crate::{ build_official_pull_plan_for_platform_inventory, build_official_sync_plan, changed_endpoint_urls, default_official_platforms, OfficialGameMainConfigBootstrapService, - OfficialLauncherBootstrapService, OfficialResourcePullPlan, OfficialResourcePullService, - YostarJpLauncherGameConfig, YostarJpLauncherManifestUrl, YostarJpLauncherRemoteManifest, + OfficialLauncherBootstrapService, OfficialResourcePullPlan, OfficialResourcePullProgress, + OfficialResourcePullProgressKind, OfficialResourcePullService, YostarJpLauncherGameConfig, + YostarJpLauncherManifestUrl, YostarJpLauncherRemoteManifest, }; use bat_adapters::official::game_main_config::YostarJpGameMainConfig; use bat_adapters::official::inventory::{ @@ -385,6 +386,25 @@ pub struct OfficialUpdateReport { pub snapshot_written: Option, } +/// Human-readable progress emitted while one official update run is executing. +#[derive(Debug, Clone, PartialEq, Eq)] +pub struct OfficialUpdateProgress { + /// Stable progress stage label. + pub stage: &'static str, + /// Human-readable status line. + pub message: String, +} + +impl OfficialUpdateProgress { + /// Creates a progress event. + pub fn new(stage: &'static str, message: impl Into) -> Self { + Self { + stage, + message: message.into(), + } + } +} + /// Official update runner. #[derive(Debug, Clone, Default)] pub struct OfficialUpdateService; @@ -397,10 +417,40 @@ impl OfficialUpdateService { /// Executes one official update run. pub fn run(&self, config: &OfficialUpdateConfig) -> anyhow::Result { + self.run_with_progress(config, |_| {}) + } + + /// Executes one official update run and emits human-readable progress + /// events. Structured reports are still returned separately. + pub fn run_with_progress( + &self, + config: &OfficialUpdateConfig, + mut progress: impl FnMut(OfficialUpdateProgress), + ) -> anyhow::Result { + progress(OfficialUpdateProgress::new( + "start", + format!( + "starting official resource sync: output={} dry_run={} auto_discover={}", + config.output_root.display(), + config.dry_run, + config.auto_discover + ), + )); + let _lock = if config.dry_run { + progress(OfficialUpdateProgress::new( + "lock", + "dry-run: skipping state lock", + )); None } else { - Some(OfficialUpdateLock::acquire(config)?) + progress(OfficialUpdateProgress::new( + "lock", + format!("acquiring state lock {}", config.lock_path().display()), + )); + let lock = OfficialUpdateLock::acquire(config)?; + progress(OfficialUpdateProgress::new("lock", "state lock acquired")); + Some(lock) }; let default_platforms = default_official_platforms(); @@ -416,14 +466,27 @@ impl OfficialUpdateService { let bootstrap_cache_path = config.bootstrap_cache_path(); let bootstrap = if config.auto_discover { + progress(OfficialUpdateProgress::new( + "bootstrap", + format!( + "auto-discover enabled; launcher_version={} cache={}", + config.launcher_version, + bootstrap_cache_path.display() + ), + )); Some(resolve_bootstrap( &config.launcher_version, &config.curl_command, &config.unzip_command, &bootstrap_cache_path, !config.dry_run, + &mut progress, )?) } else { + progress(OfficialUpdateProgress::new( + "bootstrap", + "auto-discover disabled; using explicit metadata inputs", + )); None }; @@ -451,8 +514,24 @@ impl OfficialUpdateService { "missing connection group; pass it explicitly or enable auto-discover" ) })?; + progress(OfficialUpdateProgress::new( + "metadata", + format!( + "using app_version={} connection_group={} platforms={}", + app_version, + connection_group, + platforms_label(platforms) + ), + )); let server_info_bytes = if let Some(source) = config.server_info_source.as_ref() { + progress(OfficialUpdateProgress::new( + "server-info", + format!( + "loading server-info from {}", + server_info_source_label(source) + ), + )); load_server_info(source, &fetcher)? } else { let bootstrap = bootstrap.as_ref().ok_or_else(|| { @@ -467,19 +546,47 @@ impl OfficialUpdateService { .ok_or_else(|| { anyhow::anyhow!("official GameMainConfig has no ServerInfoDataUrl") })?; + progress(OfficialUpdateProgress::new( + "server-info", + format!("fetching discovered server-info {url}"), + )); fetcher.fetch_bytes(url).map_err(anyhow::Error::msg)? }; + progress(OfficialUpdateProgress::new( + "server-info", + format!("parsing server-info bytes={}", server_info_bytes.len()), + )); let server_info = YostarJpServerInfo::from_slice(&server_info_bytes)?; let current_snapshot = server_info .sync_snapshot(&connection_group, &app_version, platforms) .map_err(anyhow::Error::msg)?; - let endpoint_markers = collect_endpoint_markers(&fetcher, ¤t_snapshot)?; + progress(OfficialUpdateProgress::new( + "discovery", + format!( + "resolved addressables_root={} endpoints={}", + current_snapshot.addressables_root, + current_snapshot.endpoints.len() + ), + )); + progress(OfficialUpdateProgress::new( + "markers", + format!( + "checking {} remote marker endpoints", + marker_endpoint_count(¤t_snapshot) + ), + )); + let endpoint_markers = + collect_endpoint_markers(&fetcher, ¤t_snapshot, &mut progress)?; let current_update_snapshot = OfficialUpdateSnapshot::new( current_snapshot.clone(), endpoint_markers, bootstrap.as_ref(), ); + progress(OfficialUpdateProgress::new( + "snapshot", + format!("reading previous snapshot {}", snapshot_path.display()), + )); let previous_snapshot = read_snapshot(&snapshot_path)?; let previous_base_snapshot = previous_snapshot .as_ref() @@ -491,18 +598,48 @@ impl OfficialUpdateService { let changed_urls = changed_endpoint_urls(&sync_plan.delta); let remote_should_download = config.force || sync_plan.should_download() || extended_delta.has_changes(); + progress(OfficialUpdateProgress::new( + "decision", + format!( + "remote decision={:?} force={} remote_should_download={}", + sync_plan.decision, config.force, remote_should_download + ), + )); let pull_plan = if config.audit_local || remote_should_download || config.plan { + progress(OfficialUpdateProgress::new( + "plan", + "building official pull plan from seed catalogs", + )); Some(build_pull_plan( &server_info, &connection_group, &app_version, platforms, &fetcher, + &mut progress, )?) } else { + progress(OfficialUpdateProgress::new( + "plan", + "pull plan not needed for clean remote state and disabled plan output", + )); None }; + if let Some(pull_plan) = pull_plan.as_ref() { + let url_count = pull_plan.all_urls().map_err(anyhow::Error::msg)?.len(); + progress(OfficialUpdateProgress::new( + "plan", + format!("pull plan contains {url_count} official URLs"), + )); + } let local_audit = if config.audit_local { + progress(OfficialUpdateProgress::new( + "audit", + format!( + "auditing local download manifest {}", + fetcher.download_manifest_path().display() + ), + )); Some( fetcher .audit_local_manifest( @@ -513,6 +650,10 @@ impl OfficialUpdateService { .map_err(anyhow::Error::msg)?, ) } else { + progress(OfficialUpdateProgress::new( + "audit", + "local manifest audit disabled", + )); None }; let local_manifest_verified_count = local_audit @@ -529,6 +670,20 @@ impl OfficialUpdateService { .map(|audit| !audit.is_clean()) .unwrap_or(false); let should_download = remote_should_download || repair_needed; + progress(OfficialUpdateProgress::new( + "audit", + format!( + "local manifest verified={} repair_needed={}", + local_manifest_verified_count, local_manifest_repair_needed_count + ), + )); + progress(OfficialUpdateProgress::new( + "decision", + format!( + "final should_download={} repair_needed={}", + should_download, repair_needed + ), + )); let mut report = OfficialUpdateReport { update_status: if should_download { OfficialUpdateStatus::WouldDownload @@ -572,6 +727,10 @@ impl OfficialUpdateService { }; if !should_download { + progress(OfficialUpdateProgress::new( + "finish", + "up to date; no download needed", + )); return Ok(report); } @@ -586,18 +745,61 @@ impl OfficialUpdateService { .map_err(anyhow::Error::msg)?; report.download_url_count = Some(urls.len()); report.download_urls = urls; + progress(OfficialUpdateProgress::new( + "dry-run", + format!( + "dry-run plan generated {} URLs", + report.download_url_count.unwrap_or(0) + ), + )); + } else { + progress(OfficialUpdateProgress::new( + "dry-run", + "dry-run detected pending download; full URL plan disabled", + )); } report.update_status = OfficialUpdateStatus::WouldDownload; + progress(OfficialUpdateProgress::new( + "finish", + "dry-run finished without writing state", + )); return Ok(report); } let pull_plan = pull_plan .as_ref() .ok_or_else(|| anyhow::anyhow!("download requested but no pull plan exists"))?; - let pull_report = fetcher.pull(pull_plan).map_err(anyhow::Error::msg)?; + let download_url_count = pull_plan.all_urls().map_err(anyhow::Error::msg)?.len(); + progress(OfficialUpdateProgress::new( + "download", + format!("downloading or reusing {download_url_count} official URLs"), + )); + let pull_report = fetcher + .pull_with_progress(pull_plan, |event| { + progress(progress_from_pull_event(event)); + }) + .map_err(anyhow::Error::msg)?; + progress(OfficialUpdateProgress::new( + "download", + format!( + "download phase finished: downloaded={} resumed={} skipped={} transferred_bytes={}", + pull_report.downloaded_count(), + pull_report.resumed_count(), + pull_report.skipped_count(), + pull_report.transferred_bytes() + ), + )); + progress(OfficialUpdateProgress::new( + "audit", + "running final local manifest audit", + )); let final_audit = fetcher .audit_local_manifest(pull_plan) .map_err(anyhow::Error::msg)?; + progress(OfficialUpdateProgress::new( + "snapshot", + format!("writing snapshot {}", snapshot_path.display()), + )); write_snapshot(&snapshot_path, ¤t_update_snapshot)?; report.update_status = OfficialUpdateStatus::Downloaded; @@ -612,6 +814,14 @@ impl OfficialUpdateService { report.local_manifest_repair_needed_count = final_audit.repair_needed_count(); report.snapshot_written = Some(snapshot_path); + progress(OfficialUpdateProgress::new( + "finish", + format!( + "sync finished: resources={} official_hashes_verified={}", + report.resource_count.unwrap_or(0), + report.official_seed_hash_verified_count + ), + )); Ok(report) } } @@ -622,11 +832,25 @@ fn build_pull_plan( app_version: &str, platforms: &[PatchPlatform], fetcher: &OfficialResourcePullService, + progress: &mut dyn FnMut(OfficialUpdateProgress), ) -> anyhow::Result { let discovery = server_info .discovery_plan(connection_group, app_version, platforms) .map_err(anyhow::Error::msg)?; - let seed_catalogs = fetch_seed_catalogs(fetcher, &discovery)?; + progress(OfficialUpdateProgress::new( + "plan", + format!( + "discovery plan resolved: connection_group={} app_version={} endpoints={}", + discovery.connection_group_name, + discovery.app_version, + discovery.endpoints.len() + ), + )); + let seed_catalogs = fetch_seed_catalogs(fetcher, &discovery, progress)?; + progress(OfficialUpdateProgress::new( + "inventory", + "parsing seed catalogs into download inventory", + )); let inventory = build_inventory_from_seed_catalogs(&seed_catalogs, platforms)?; Ok(build_official_pull_plan_for_platform_inventory( discovery, inventory, platforms, @@ -652,6 +876,7 @@ fn load_server_info( fn collect_endpoint_markers( fetcher: &OfficialResourcePullService, snapshot: &YostarJpSyncSnapshot, + progress: &mut dyn FnMut(OfficialUpdateProgress), ) -> anyhow::Result> { let mut markers = Vec::new(); @@ -659,6 +884,15 @@ fn collect_endpoint_markers( let Some(role) = marker_role(endpoint.kind) else { continue; }; + progress(OfficialUpdateProgress::new( + "marker", + format!( + "fetching {} marker{} {}", + endpoint_kind_label(endpoint.kind), + platform_suffix(endpoint.platform), + endpoint.url + ), + )); let bytes = fetcher .fetch_bytes(&endpoint.url) .map_err(anyhow::Error::msg)?; @@ -689,6 +923,78 @@ fn marker_role(kind: YostarJpResourceEndpointKind) -> Option usize { + snapshot + .endpoints + .iter() + .filter(|endpoint| marker_role(endpoint.kind).is_some()) + .count() +} + +fn server_info_source_label(source: &OfficialServerInfoSource) -> String { + match source { + OfficialServerInfoSource::LocalPath(path) => format!("local path {}", path.display()), + OfficialServerInfoSource::OfficialFile(file_name) => { + format!("official file {file_name}") + } + OfficialServerInfoSource::OfficialUrl(url) => format!("official URL {url}"), + } +} + +fn platforms_label(platforms: &[PatchPlatform]) -> String { + platforms + .iter() + .map(|platform| platform.as_str()) + .collect::>() + .join(",") +} + +fn endpoint_kind_label(kind: YostarJpResourceEndpointKind) -> &'static str { + match kind { + YostarJpResourceEndpointKind::TableCatalog => "table_catalog", + YostarJpResourceEndpointKind::TableCatalogHash => "table_catalog_hash", + YostarJpResourceEndpointKind::AddressablesCatalog => "addressables_catalog", + YostarJpResourceEndpointKind::AddressablesCatalogHash => "addressables_catalog_hash", + YostarJpResourceEndpointKind::BundlePackingInfo => "bundle_packing_info", + YostarJpResourceEndpointKind::BundlePackingInfoHash => "bundle_packing_info_hash", + YostarJpResourceEndpointKind::MediaCatalog => "media_catalog", + YostarJpResourceEndpointKind::MediaCatalogHash => "media_catalog_hash", + } +} + +fn platform_suffix(platform: Option) -> String { + platform + .map(|platform| format!(" ({})", platform.as_str())) + .unwrap_or_default() +} + +fn progress_from_pull_event(event: OfficialResourcePullProgress) -> OfficialUpdateProgress { + match event.kind { + OfficialResourcePullProgressKind::Started => OfficialUpdateProgress::new( + "download", + format!("({}/{}) started {}", event.index, event.total, event.url), + ), + OfficialResourcePullProgressKind::Finished => { + let status = event + .status + .map(|status| status.as_str()) + .unwrap_or("unknown"); + OfficialUpdateProgress::new( + "download", + format!( + "({}/{}) finished status={} bytes={} transferred_bytes={} {}", + event.index, + event.total, + status, + event.bytes.unwrap_or(0), + event.transferred_bytes.unwrap_or(0), + event.url + ), + ) + } + } +} + /// Computes the extended snapshot delta. pub fn diff_extended_snapshot( current: &OfficialUpdateSnapshot, @@ -817,21 +1123,41 @@ fn resolve_bootstrap( unzip_command: &Path, cache_path: &Path, write_cache: bool, + progress: &mut dyn FnMut(OfficialUpdateProgress), ) -> anyhow::Result { let launcher = OfficialLauncherBootstrapService::with_curl_command( launcher_version, curl_command.to_string_lossy().to_string(), ); + progress(OfficialUpdateProgress::new( + "launcher", + "fetching official launcher game config and remote manifest", + )); let (game_config, manifest_url, manifest) = launcher .fetch_latest_remote_manifest() .map_err(anyhow::Error::msg)?; let launcher_metadata = launcher_metadata_from_parts(launcher_version, &game_config, &manifest_url, &manifest); + progress(OfficialUpdateProgress::new( + "launcher", + format!( + "launcher metadata resolved: latest_version={} manifest_files={}", + launcher_metadata.game_latest_version, launcher_metadata.manifest_file_count + ), + )); + progress(OfficialUpdateProgress::new( + "bootstrap-cache", + format!("checking bootstrap cache {}", cache_path.display()), + )); if let Some(cache) = read_bootstrap_cache(cache_path)? { if let Some(game_main_config) = cached_game_main_config_for_metadata(&cache, &launcher_metadata) { + progress(OfficialUpdateProgress::new( + "bootstrap-cache", + "cache hit; reusing parsed GameMainConfig", + )); return Ok(ResolvedBootstrap { launcher_metadata, game_main_config, @@ -840,6 +1166,10 @@ fn resolve_bootstrap( } } + progress(OfficialUpdateProgress::new( + "game-main-config", + "cache miss; fetching resources.assets and parsing GameMainConfig", + )); let bootstrapper = OfficialGameMainConfigBootstrapService::with_commands( launcher_version, curl_command.to_path_buf(), @@ -867,6 +1197,15 @@ fn resolve_bootstrap( game_main_config: game_main_config.clone(), }, )?; + progress(OfficialUpdateProgress::new( + "bootstrap-cache", + format!("bootstrap cache written {}", cache_path.display()), + )); + } else { + progress(OfficialUpdateProgress::new( + "bootstrap-cache", + "dry-run: bootstrap cache not written", + )); } Ok(ResolvedBootstrap { @@ -879,6 +1218,7 @@ fn resolve_bootstrap( fn fetch_seed_catalogs( fetcher: &OfficialResourcePullService, discovery: &YostarJpResourceDiscoveryPlan, + progress: &mut dyn FnMut(OfficialUpdateProgress), ) -> anyhow::Result { let mut catalogs = SeedCatalogs::default(); @@ -892,6 +1232,15 @@ fn fetch_seed_catalogs( continue; } + progress(OfficialUpdateProgress::new( + "catalog", + format!( + "fetching seed catalog {}{} {}", + endpoint_kind_label(endpoint.kind), + platform_suffix(endpoint.platform), + endpoint.url + ), + )); let bytes = fetcher .fetch_bytes(&endpoint.url) .map_err(anyhow::Error::msg)?; diff --git a/infrastructure/tests/official_game_main_config_bootstrap.rs b/infrastructure/tests/official_game_main_config_bootstrap.rs index e8d4abd..676cd20 100644 --- a/infrastructure/tests/official_game_main_config_bootstrap.rs +++ b/infrastructure/tests/official_game_main_config_bootstrap.rs @@ -8,7 +8,8 @@ use bat_adapters::official::yostar_jp::{ }; use bat_infrastructure::{ build_official_pull_plan_from_platform_inventory, OfficialGameMainConfigBootstrapService, - OfficialResourcePullService, + OfficialResourcePullService, OfficialUpdateConfig, OfficialUpdateProgress, + OfficialUpdateService, OfficialUpdateStatus, }; use std::collections::HashMap; use std::fs; @@ -151,6 +152,39 @@ fn official_pipeline_can_dry_run_and_pull_without_local_client() { assert!(!curl_log.contains("bluearchive.cafe")); } +#[test] +fn official_update_service_emits_human_progress_events() { + let harness = TestHarness::new(); + let config = OfficialUpdateConfig { + auto_discover: true, + launcher_version: TEST_LAUNCHER_VERSION.to_string(), + output_root: harness.temp.path().join("sync-output"), + curl_command: harness.curl_script.clone(), + unzip_command: harness.unzip_script.clone(), + dry_run: true, + plan: true, + ..OfficialUpdateConfig::default() + }; + let mut events = Vec::::new(); + + let report = OfficialUpdateService::new() + .run_with_progress(&config, |event| events.push(event)) + .unwrap(); + + assert_eq!(report.update_status, OfficialUpdateStatus::WouldDownload); + assert_eq!(report.download_url_count, Some(19)); + assert!(events.iter().any(|event| event.stage == "start")); + assert!(events.iter().any(|event| event.stage == "launcher")); + assert!(events.iter().any(|event| event.stage == "server-info")); + assert!(events.iter().any(|event| event.stage == "marker")); + assert!(events.iter().any(|event| event.stage == "catalog")); + assert!(events.iter().any(|event| event.stage == "dry-run")); + assert!(events.iter().any(|event| event.stage == "finish")); + assert!(events.iter().any(|event| event + .message + .contains("pull plan contains 19 official URLs"))); +} + struct TestHarness { temp: TempDir, curl_script: std::path::PathBuf,