jpmschweitzer/settled-reach
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

feat(ci): tracing JSON format in CI, tick duration logging, schedule dump (#344, #346)

Browse Source 
Tracing (#344):
- Add 'json' feature to tracing-subscriber dependency
- Emit JSON log format when CI=true or RUST_LOG_FORMAT=json is set
  (structured log ingestion in CI pipelines)
- Add tracing::debug! with tick_ms/budget_ms/over_budget fields on each
  tick for performance profiling and tier system debugging prerequisite

Schedule dump (#346):
- Add --dump-schedule CLI flag that prints bevy_ecs schedule graph and exits
  without requiring TCP bridge or world setup
- Add make debug-schedule target for CI artifact generation and diff-based
  regression detection of unintended system reordering

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
jpmschweitzer
2026-02-19 14:15:46 +01:00
co-authored by Claude Sonnet 4.6
parent 6a7dc915de
commit a71218f6bc
4 changed files with 109 additions and 13 deletions
Download Patch File Download Diff File Expand all files Collapse all files
Makefile
+8 -1
View File
@@ -7,7 +7,7 @@ GODOT := $(shell command -v godot4 2>/dev/null || command -v godot 2>/dev/null)
pre-pr-server pre-pr-client pre-pr-content \
fixtures-client golden-diff golden-update \
checklist-validate checklist-generate \
perf-baseline
perf-baseline debug-schedule
# --- Configuration ---
@@ -53,6 +53,7 @@ help:
@echo " make pre-pr-content Content-scoped pre-PR (schema + cross-ref validation)"
@echo ""
@echo " make setup-hooks Install pre-commit hooks (included in setup)"
@echo " make debug-schedule Print bevy_ecs schedule graph (diff for PR artifacts)"
@echo ""
@echo " GODOT_VERSION=4.6 make setup Override Godot version"
@@ -285,6 +286,12 @@ checklist-generate:
perf-baseline:
@tooling/perf-baseline
# --- Schedule debug (#346) ---
debug-schedule:
@echo "Dumping bevy_ecs schedule graph..."
@cd server && cargo run -- --dump-schedule
content-ron:
cd tooling/content-converter && cargo build --release
tooling/content-converter/target/release/content-converter --input content --output content-ron --verbose
server/Cargo.lock
Generated
+14 -1
View File
@@ -978,7 +978,7 @@ dependencies = [
[[package]]
name = "settled-reach-server"
version = "0.1.10"
version = "0.1.11"
dependencies = [
"bevy_app",
"bevy_ecs",
@@ -1162,6 +1162,16 @@ dependencies = [
"tracing-core",
]
[[package]]
name = "tracing-serde"
version = "0.2.0"
source = "registry+https://github.com/rust-lang/crates.io-index"
checksum = "704b1aeb7be0d0a84fc9828cae51dab5970fee5088f83d1dd7ee6f6246fc6ff1"
dependencies = [
"serde",
"tracing-core",
]
[[package]]
name = "tracing-subscriber"
version = "0.3.22"
@@ -1172,12 +1182,15 @@ dependencies = [
"nu-ansi-term",
"once_cell",
"regex-automata",
"serde",
"serde_json",
"sharded-slab",
"smallvec",
"thread_local",
"tracing",
"tracing-core",
"tracing-log",
"tracing-serde",
]
[[package]]
server/Cargo.toml
+1 -1
View File
@@ -15,7 +15,7 @@ rand_chacha = "0.9"
pathfinding = "4.11"
thiserror = "2"
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }
tracing-subscriber = { version = "0.3", features = ["env-filter", "json"] }
[features]
default = ["gauntlet"]
server/src/main.rs
+86 -10
View File
@@ -2,9 +2,10 @@
// Entry point for standalone simulation binary
//
// Supports --test-mode for automated testing:
// --test-mode Enable test mode (fixed seed, LISTENING signal, quieter logs)
// --port <PORT> Bind to specific port (0 = OS-assigned). Overrides positional addr.
// --seed <SEED> RNG seed (default: 0, test-mode default: 42)
// --test-mode Enable test mode (fixed seed, LISTENING signal, quieter logs)
// --port <PORT> Bind to specific port (0 = OS-assigned). Overrides positional addr.
// --seed <SEED> RNG seed (default: 0, test-mode default: 42)
// --dump-schedule Print bevy_ecs schedule graph and exit (no TCP required)
use bevy_app::prelude::*;
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
@@ -16,6 +17,7 @@ use settled_reach_server::simulation::SimulationPlugin;
fn main() {
let args: Vec<String> = std::env::args().collect();
let test_mode = args.iter().any(|a| a == "--test-mode");
let dump_schedule = args.iter().any(|a| a == "--dump-schedule");
let port_flag = args
.iter()
@@ -31,18 +33,32 @@ fn main() {
// Tracing: quieter in test mode, always to stderr so stdout stays clean
// for the LISTENING:{port} handshake signal.
// CI=true → JSON format for structured log ingestion.
// RUST_LOG_FORMAT=json → same effect for local debugging.
let default_filter = if test_mode {
"settled_reach_server=warn"
} else {
"settled_reach_server=debug"
};
tracing_subscriber::registry()
.with(
tracing_subscriber::EnvFilter::try_from_default_env()
.unwrap_or_else(|_| default_filter.into()),
)
.with(tracing_subscriber::fmt::layer().with_writer(std::io::stderr))
.init();
let env_filter = tracing_subscriber::EnvFilter::try_from_default_env()
.unwrap_or_else(|_| default_filter.into());
let use_json =
std::env::var("CI").is_ok() || std::env::var("RUST_LOG_FORMAT").as_deref() == Ok("json");
if use_json {
tracing_subscriber::registry()
.with(env_filter)
.with(
tracing_subscriber::fmt::layer()
.json()
.with_writer(std::io::stderr),
)
.init();
} else {
tracing_subscriber::registry()
.with(env_filter)
.with(tracing_subscriber::fmt::layer().with_writer(std::io::stderr))
.init();
}
// Resolve bind address.
// --port flag overrides everything (most common in test mode).
@@ -76,6 +92,13 @@ fn main() {
.unwrap_or_else(|| "127.0.0.1:9876".to_string())
};
// --dump-schedule: print bevy_ecs schedule graph and exit (no TCP required).
// Useful for PR artifacts and detecting unintended system reordering (#346).
if dump_schedule {
dump_schedule_graph();
return;
}
// Bind FIRST, print port, THEN accept.
// Critical for --port 0: the OS assigns a random port at bind time.
// The LISTENING:{port} line is the handshake signal for the test client.
@@ -147,6 +170,12 @@ fn main() {
}
let elapsed = frame_start.elapsed();
tracing::debug!(
tick_ms = elapsed.as_millis(),
budget_ms = target_frame_time.as_millis(),
over_budget = elapsed > target_frame_time,
"tick"
);
if elapsed < target_frame_time {
std::thread::sleep(target_frame_time - elapsed);
}
@@ -155,6 +184,53 @@ fn main() {
tracing::info!("Simulation server shutting down");
}
/// Print bevy_ecs schedule graph and exit.
/// Invoked by --dump-schedule CLI flag (#346).
///
/// Print bevy_ecs schedule graph and exit.
/// Invoked by --dump-schedule CLI flag (#346).
///
/// Builds the full app with all plugins (no TCP bridge or world entities),
/// then prints each registered schedule and its system count to stdout.
/// Systems are counted from the registered (pre-initialization) graph, so
/// counts reflect what was registered by plugins.
///
/// CI integration: run on each PR via `make debug-schedule`, diff output
/// against a committed baseline to catch unintended system reordering.
fn dump_schedule_graph() {
use bevy_ecs::schedule::Schedules;
let mut app = App::new();
app.add_plugins(SimulationPlugin);
app.add_plugins(BridgePlugin);
app.add_plugins(settled_reach_server::knowledge::KnowledgePlugin);
app.add_plugins(settled_reach_server::npc::NpcPlugin);
app.add_plugins(settled_reach_server::content::ContentPlugin);
app.insert_resource(settled_reach_server::simulation::rng::SimRng::new(0));
// Access Schedules resource directly — schedules are populated by plugins
// via add_systems() before any tick runs. No app.update() needed here:
// running a tick would require full world setup (WalkabilityMap, etc.) that
// isn't needed for schedule inspection.
let world = app.world();
let schedules = world.resource::<Schedules>();
println!("=== Schedule Graph (settled-reach-server) ===");
let mut entries: Vec<String> = schedules
.iter()
.map(|(label, schedule)| format!(" {:?} [{} systems]", label, schedule.systems_len()))
.collect();
entries.sort(); // deterministic output for baseline diffs
let schedule_count = entries.len();
for entry in &entries {
println!("{}", entry);
}
println!("=== {} schedules total ===", schedule_count);
println!();
println!("Note: use RUST_LOG=trace with the live server for per-tick timing.");
println!(" system names visible with `cargo build --features bevy/debug`.");
}
/// Proof room: 32x32 map, wall at (16,14), player at (16,16), 3 NPCs.
/// Extracted from the original inline setup for reuse by both test-mode and normal mode.
fn setup_proof_room(app: &mut App) {