Skip to content

Commit 54ba1fd

Browse files
committed
More otel debug tracing
1 parent 041c1be commit 54ba1fd

5 files changed

Lines changed: 93 additions & 22 deletions

File tree

rewatch/src/build/compile_dependencies.rs

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,13 @@ pub fn compile_dependencies(
2727
.cloned()
2828
.collect();
2929

30+
tracing::debug!(
31+
starts = ?module_names.iter().collect::<Vec<_>>(),
32+
closure_size = closure.len(),
33+
needs_compile_count = needs_compile.len(),
34+
"compile_dependencies: closure computed"
35+
);
36+
3037
let params = CompileParams {
3138
modules: closure,
3239
filter: CompileFilter::DirtyOnly(needs_compile),
@@ -53,6 +60,12 @@ pub fn compile_dependencies(
5360

5461
if !result.compile_errors.is_empty() {
5562
let _error_span = info_span!("build.compile_error", error = %result.compile_errors).entered();
63+
if !result.skipped_modules.is_empty() {
64+
tracing::debug!(
65+
skipped = ?result.skipped_modules.iter().collect::<Vec<_>>(),
66+
"compile_dependencies: modules skipped due to errors"
67+
);
68+
}
5669
Err(IncrementalBuildError {
5770
kind: IncrementalBuildErrorKind::CompileError(None),
5871
output_mode: OutputMode::Silent,

rewatch/src/build/full_typecheck.rs

Lines changed: 7 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -39,12 +39,18 @@ pub fn full_typecheck(
3939

4040
if !result.compile_errors.is_empty() {
4141
let _error_span = info_span!("build.compile_error", error = %result.compile_errors).entered();
42+
if !result.skipped_modules.is_empty() {
43+
tracing::debug!(
44+
skipped = ?result.skipped_modules.iter().collect::<Vec<_>>(),
45+
"full_typecheck: modules skipped due to errors"
46+
);
47+
}
4248
Err(IncrementalBuildError {
4349
kind: IncrementalBuildErrorKind::CompileError(None),
4450
output_mode: OutputMode::Silent,
4551
diagnostics: result.to_diagnostics(),
4652
modules: Box::new(params.modules),
47-
skipped_modules: Box::default(),
53+
skipped_modules: Box::new(result.skipped_modules),
4854
})
4955
} else {
5056
write_compiler_info(build_state, OutputTarget::Lsp);

rewatch/src/lsp/queue.rs

Lines changed: 21 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -617,14 +617,33 @@ async fn flush_inner(
617617
// full_compile_intent. Intent drain piggybacks on the same
618618
// take-build-replace cycle — no extra locking needed.
619619
let errored_files = if has_incremental_builds || (has_full_builds && has_pending_intents) {
620-
file_build::run(
620+
if has_pending_intents {
621+
for (root, names) in state.full_compile_intent.iter() {
622+
tracing::debug!(
623+
project = %root.display(),
624+
modules = ?names.iter().collect::<Vec<_>>(),
625+
"flush: full_compile_intent before file_build"
626+
);
627+
}
628+
}
629+
let errored = file_build::run(
621630
&compile_files,
622631
&mut state.full_compile_intent,
623632
projects,
624633
client,
625634
store_ref,
626635
)
627-
.await
636+
.await;
637+
if !state.full_compile_intent.is_empty() {
638+
for (root, names) in state.full_compile_intent.iter() {
639+
tracing::debug!(
640+
project = %root.display(),
641+
modules = ?names.iter().collect::<Vec<_>>(),
642+
"flush: full_compile_intent remaining after file_build"
643+
);
644+
}
645+
}
646+
errored
628647
} else {
629648
HashSet::new()
630649
};

rewatch/src/lsp/queue/file_build.rs

Lines changed: 38 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -290,7 +290,7 @@ fn build_batch(
290290
let mut intent_names = intent.unwrap_or_default();
291291
if !skipped_modules.is_empty() {
292292
tracing::debug!(
293-
skipped_count = skipped_modules.len(),
293+
skipped = ?skipped_modules.iter().collect::<Vec<_>>(),
294294
"build_batch: registering skipped modules as FullCompile intent"
295295
);
296296
intent_names.extend(skipped_modules);
@@ -516,33 +516,45 @@ fn drain_full_compile_intent(
516516
let mut pending = AHashSet::new();
517517
let mut not_ready = HashSet::new();
518518

519+
let mut already_built = Vec::new();
520+
let mut discarded = Vec::new();
521+
519522
for name in names {
520523
match build_state.build_state.modules.get(&name) {
521524
Some(Module::SourceFile(sf)) => match sf.compilation_stage() {
522525
CompilationStage::Built(..) => {
523-
// Already compiled — nothing to do.
526+
already_built.push(name);
524527
}
525528
CompilationStage::TypeChecked { .. } => {
526529
pending.insert(name);
527530
}
528-
_ => {
529-
// Not ready yet (e.g. CompileError, SourceDirty).
531+
other => {
532+
tracing::debug!(
533+
module = %name,
534+
stage = ?std::mem::discriminant(other),
535+
"drain_intent: module not ready"
536+
);
530537
not_ready.insert(name);
531538
}
532539
},
533540
_ => {
534-
// Module no longer exists — discard.
541+
discarded.push(name);
535542
}
536543
}
537544
}
538545

546+
tracing::debug!(
547+
built_count = already_built.len(),
548+
pending_count = pending.len(),
549+
not_ready_count = not_ready.len(),
550+
discarded_count = discarded.len(),
551+
built = ?already_built,
552+
pending_modules = ?pending.iter().collect::<Vec<_>>(),
553+
not_ready_modules = ?not_ready.iter().collect::<Vec<_>>(),
554+
"drain_intent: partition"
555+
);
556+
539557
if pending.is_empty() {
540-
if !not_ready.is_empty() {
541-
tracing::debug!(
542-
"drain_intent: no TypeChecked modules to compile ({} still pending)",
543-
not_ready.len()
544-
);
545-
}
546558
return not_ready;
547559
}
548560

@@ -563,7 +575,14 @@ fn drain_full_compile_intent(
563575
}
564576
Err(e) => {
565577
tracing::warn!("drain_intent completed with errors: {e}");
578+
if !e.skipped_modules.is_empty() {
579+
tracing::debug!(
580+
skipped = ?e.skipped_modules.iter().collect::<Vec<_>>(),
581+
"drain_intent: skipped modules from compile_dependencies"
582+
);
583+
}
566584
// Keep failed modules in intent for next attempt.
585+
let mut became_built = Vec::new();
567586
for name in &pending {
568587
if build_state.build_state.modules.get(name).is_some_and(|m| {
569588
!matches!(
@@ -573,8 +592,16 @@ fn drain_full_compile_intent(
573592
)
574593
}) {
575594
not_ready.insert(name.clone());
595+
} else {
596+
became_built.push(name.clone());
576597
}
577598
}
599+
if !became_built.is_empty() {
600+
tracing::debug!(
601+
modules = ?became_built,
602+
"drain_intent: modules reached Built despite errors (dropped from intent)"
603+
);
604+
}
578605
diagnostics.extend(e.diagnostics);
579606
touched_files.extend(module_names_to_paths(build_state, &e.modules));
580607
}

rewatch/src/lsp/queue/project_build.rs

Lines changed: 14 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -269,6 +269,12 @@ pub(super) async fn run(
269269
}
270270
}
271271

272+
tracing::debug!(
273+
built_snapshot_modules = ?built_snap.keys().collect::<Vec<_>>(),
274+
error_fullcompile_modules = ?error_fc.iter().collect::<Vec<_>>(),
275+
"project_build: snapshot from old state"
276+
);
277+
272278
(
273279
collect_source_uris(old_state),
274280
old_state.get_warn_error_override().clone(),
@@ -344,14 +350,14 @@ pub(super) async fn run(
344350
}
345351
}
346352

347-
if promoted > 0 || !intent.is_empty() {
348-
tracing::debug!(
349-
project = %project_root.display(),
350-
promoted,
351-
intent_count = intent.len(),
352-
"project_build: hash promotion results"
353-
);
354-
}
353+
tracing::debug!(
354+
project = %project_root.display(),
355+
snapshot_size = built_snapshot.len(),
356+
promoted,
357+
intent_count = intent.len(),
358+
intent_modules = ?intent.iter().collect::<Vec<_>>(),
359+
"project_build: hash promotion results"
360+
);
355361

356362
// Replace state under lock
357363
if let Ok(mut guard) = projects_clone.lock() {

0 commit comments

Comments
 (0)