Skip to content

Commit 6557293

Browse files
tyao1meta-codesync[bot]
authored andcommitted
Add write_artifacts sub-timers to commit_project telemetry
Reviewed By: evanyeung Differential Revision: D94388099 fbshipit-source-id: c215c5893bcd78483fd577deed73970a70105216
1 parent 0dba7f7 commit 6557293

1 file changed

Lines changed: 70 additions & 3 deletions

File tree

compiler/crates/relay-compiler/src/build_project.rs

Lines changed: 70 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,9 @@ mod validate;
3030
use std::fmt;
3131
use std::path::PathBuf;
3232
use std::sync::Arc;
33+
use std::sync::atomic::AtomicUsize;
34+
use std::sync::atomic::Ordering;
35+
use std::time::Instant;
3336

3437
pub use artifact_generated_types::ArtifactGeneratedTypes;
3538
use build_ir::BuildIRResult;
@@ -695,6 +698,7 @@ pub async fn commit_project(
695698
&artifacts,
696699
&fragment_locations,
697700
&artifacts_file_hash_map,
701+
&log_event,
698702
)?;
699703
for artifact in &artifacts {
700704
if !existing_artifacts.remove(&artifact.path) {
@@ -731,6 +735,7 @@ pub async fn commit_project(
731735
&artifacts,
732736
&fragment_locations,
733737
&artifacts_file_hash_map,
738+
&log_event,
734739
)?;
735740
artifacts.into_par_iter().for_each(|artifact| {
736741
current_paths_map.insert(artifact);
@@ -822,6 +827,7 @@ The compiler may produce outdated artifacts, but it will regenerate the correct
822827
Ok(next_artifact_map)
823828
}
824829

830+
#[allow(clippy::too_many_arguments)]
825831
fn write_artifacts<F: Fn() -> bool + Sync + Send>(
826832
config: &Config,
827833
project_config: &ProjectConfig,
@@ -830,15 +836,37 @@ fn write_artifacts<F: Fn() -> bool + Sync + Send>(
830836
artifacts: &[Artifact],
831837
fragment_locations: &FragmentLocations,
832838
artifacts_file_hash_map: &Option<FxHashMap<String, Option<String>>>,
839+
log_event: &impl PerfLogEvent,
833840
) -> Result<(), BuildProjectFailure> {
841+
// Cumulative CPU time summed across all parallel rayon threads (not
842+
// wall-clock). Accumulated in microseconds (not millis) because
843+
// per-artifact operations are sub-millisecond — as_millis() would
844+
// truncate each to 0. Converted to ms when logging to Scuba.
845+
let codegen_us = AtomicUsize::new(0);
846+
let should_write_us = AtomicUsize::new(0);
847+
let write_us = AtomicUsize::new(0);
848+
let count_written = AtomicUsize::new(0);
849+
let count_skipped = AtomicUsize::new(0);
850+
834851
artifacts.par_chunks(8).try_for_each_init(
835852
|| Printer::with_dedupe(project_config),
836853
|printer, artifacts| {
854+
// Accumulate per-chunk to minimize atomic contention across threads.
855+
// Only one batch of atomic ops per chunk (8 artifacts) instead of
856+
// per artifact.
857+
let mut chunk_codegen_us = 0usize;
858+
let mut chunk_sw_us = 0usize;
859+
let mut chunk_write_us = 0usize;
860+
let mut chunk_written = 0usize;
861+
let mut chunk_skipped = 0usize;
862+
837863
for artifact in artifacts {
838864
if should_stop_updating_artifacts() {
839865
return Err(BuildProjectFailure::Cancelled);
840866
}
841867
let path = config.root_dir.join(&artifact.path);
868+
869+
let codegen_start = Instant::now();
842870
let content = artifact.content.as_bytes(
843871
config,
844872
project_config,
@@ -847,21 +875,60 @@ fn write_artifacts<F: Fn() -> bool + Sync + Send>(
847875
artifact.source_file,
848876
fragment_locations,
849877
);
878+
chunk_codegen_us += codegen_start.elapsed().as_micros() as usize;
879+
850880
let file_hash = match artifact.path.to_str() {
851881
Some(key) => artifacts_file_hash_map
852882
.as_ref()
853883
.and_then(|map| map.get(key).cloned().flatten()),
854884
_ => None,
855885
};
856-
if config
886+
887+
let sw_start = Instant::now();
888+
let needs_write = config
857889
.artifact_writer
858-
.should_write(&path, &content, file_hash)?
859-
{
890+
.should_write(&path, &content, file_hash)?;
891+
chunk_sw_us += sw_start.elapsed().as_micros() as usize;
892+
893+
if needs_write {
894+
let write_start = Instant::now();
860895
config.artifact_writer.write(path, content)?;
896+
chunk_write_us += write_start.elapsed().as_micros() as usize;
897+
chunk_written += 1;
898+
} else {
899+
chunk_skipped += 1;
861900
}
862901
}
902+
903+
codegen_us.fetch_add(chunk_codegen_us, Ordering::Relaxed);
904+
should_write_us.fetch_add(chunk_sw_us, Ordering::Relaxed);
905+
write_us.fetch_add(chunk_write_us, Ordering::Relaxed);
906+
count_written.fetch_add(chunk_written, Ordering::Relaxed);
907+
count_skipped.fetch_add(chunk_skipped, Ordering::Relaxed);
863908
Ok(())
864909
},
865910
)?;
911+
912+
log_event.number(
913+
"write_artifacts_codegen_cpu_time",
914+
codegen_us.load(Ordering::Relaxed) / 1000,
915+
);
916+
log_event.number(
917+
"write_artifacts_should_write_cpu_time",
918+
should_write_us.load(Ordering::Relaxed) / 1000,
919+
);
920+
log_event.number(
921+
"write_artifacts_write_cpu_time",
922+
write_us.load(Ordering::Relaxed) / 1000,
923+
);
924+
log_event.number(
925+
"write_artifacts_count_written",
926+
count_written.load(Ordering::Relaxed),
927+
);
928+
log_event.number(
929+
"write_artifacts_count_skipped",
930+
count_skipped.load(Ordering::Relaxed),
931+
);
932+
866933
Ok(())
867934
}

0 commit comments

Comments
 (0)