Skip to content

Commit

Permalink
feat(log): improved logging/output by changing levels and formatting
Browse files Browse the repository at this point in the history
  • Loading branch information
@zkat
zkat committed Mar 23, 2023
1 parent 4266daa commit e1cafd0
Show file tree
Hide file tree
Showing 4 changed files with 107 additions and 91 deletions.
26 changes: 13 additions & 13 deletions crates/node-maintainer/src/maintainer.rs
View file
Expand Up @@ -398,7 +398,7 @@ impl NodeMaintainer {
}
}

tracing::info!("No metadata file found in node_modules/. Pruned entire node_modules/ directory in {}ms.", start.elapsed().as_micros() / 1000);
tracing::debug!("No metadata file found in node_modules/. Pruned entire node_modules/ directory in {}ms.", start.elapsed().as_micros() / 1000);

// TODO: get an accurate count here?
return Ok(0);
Expand Down Expand Up @@ -501,12 +501,12 @@ impl NodeMaintainer {
}

if extraneous_packages == 0 {
tracing::info!(
tracing::debug!(
"Nothing to prune. Completed check in {}ms.",
start.elapsed().as_micros() / 1000
);
} else {
tracing::info!(
tracing::debug!(
"Pruned {extraneous_packages} extraneous package{} in {}ms.",
start.elapsed().as_micros() / 1000,
if extraneous_packages == 1 { "" } else { "s" },
Expand Down Expand Up @@ -566,13 +566,13 @@ impl NodeMaintainer {
on_extract(&self.graph[child_idx].package);
}

tracing::debug!(
"Extracted {} to {} in {:?}ms. {}/{total} done. {} in flight.",
tracing::trace!(
in_flight = concurrent_count.fetch_sub(1, atomic::Ordering::SeqCst) - 1,
"Extracted {} to {} in {:?}ms. {}/{total} done.",
self.graph[child_idx].package.name(),
target_dir.display(),
start.elapsed().as_millis(),
total_completed.fetch_add(1, atomic::Ordering::SeqCst) + 1,
concurrent_count.fetch_sub(1, atomic::Ordering::SeqCst) - 1
);
Ok::<_, NodeMaintainerError>(())
},
Expand All @@ -583,7 +583,7 @@ impl NodeMaintainer {
self.to_kdl()?.to_string(),
)?;
let actually_extracted = actually_extracted.load(atomic::Ordering::SeqCst);
tracing::info!(
tracing::debug!(
"Extracted {actually_extracted} package{} in {}ms.",
if actually_extracted == 1 { "" } else { "s" },
start.elapsed().as_millis(),
Expand Down Expand Up @@ -813,7 +813,7 @@ impl NodeMaintainer {
}

#[cfg(not(target_arch = "wasm32"))]
tracing::info!(
tracing::debug!(
"Resolved graph of {} nodes in {}ms",
self.graph.inner.node_count(),
start.elapsed().as_millis()
Expand Down Expand Up @@ -1031,21 +1031,21 @@ fn supports_reflink(src_dir: &Path, dest_dir: &Path) -> bool {
let temp = match tempfile::NamedTempFile::new_in(src_dir) {
Ok(t) => t,
Err(e) => {
tracing::info!("error creating tempfile while checking for reflink support: {e}.");
tracing::debug!("error creating tempfile while checking for reflink support: {e}.");
return false;
}
};
match std::fs::write(&temp, "a") {
Ok(_) => {}
Err(e) => {
tracing::info!("error writing to tempfile while checking for reflink support: {e}.");
tracing::debug!("error writing to tempfile while checking for reflink support: {e}.");
return false;
}
};
let tempdir = match tempfile::TempDir::new_in(dest_dir) {
Ok(t) => t,
Err(e) => {
tracing::info!(
tracing::debug!(
"error creating destination tempdir while checking for reflink support: {e}."
);
return false;
Expand All @@ -1054,15 +1054,15 @@ fn supports_reflink(src_dir: &Path, dest_dir: &Path) -> bool {
let supports_reflink = reflink::reflink(temp.path(), tempdir.path().join("b"))
.map(|_| true)
.map_err(|e| {
tracing::info!(
tracing::debug!(
"reflink support check failed. Files will be hard linked or copied. ({e})"
);
e
})
.unwrap_or(false);

if supports_reflink {
tracing::info!("Verified reflink support. Extracted data will use copy-on-write reflinks instead of hard links or full copies.")
tracing::debug!("Verified reflink support. Extracted data will use copy-on-write reflinks instead of hard links or full copies.")
}

supports_reflink
Expand Down
19 changes: 5 additions & 14 deletions src/commands/ping.rs
View file
Expand Up @@ -18,9 +18,6 @@ pub struct PingCmd {

#[clap(from_global)]
json: bool,

#[clap(from_global)]
quiet: bool,
}

#[async_trait]
Expand All @@ -30,15 +27,11 @@ impl OroCommand for PingCmd {
let registry = self
.registry
.unwrap_or_else(|| "https://registry.npmjs.org".parse().unwrap());
if !self.quiet && !self.json {
eprintln!("ping: {registry}");
}
tracing::info!("ping: {registry}");
let client = OroClient::new(registry.clone());
let payload = client.ping().await?;
let time = start.elapsed().as_micros() as f32 / 1000.0;
if !self.quiet && !self.json {
eprintln!("pong: {time}ms");
}
tracing::info!("pong: {time}ms");
if self.json {
let details: Value = serde_json::from_str(&payload)
.into_diagnostic()
Expand All @@ -50,11 +43,9 @@ impl OroCommand for PingCmd {
}))
.into_diagnostic()
.wrap_err("ping::serialize")?;
if !self.quiet {
println!("{output}");
}
} else if !self.quiet {
eprintln!("payload: {payload}");
println!("{output}");
} else {
tracing::info!("payload: {payload}");
}
Ok(())
}
Expand Down
77 changes: 32 additions & 45 deletions src/commands/restore.rs
View file
Expand Up @@ -21,9 +21,6 @@ pub struct RestoreCmd {
#[clap(from_global)]
json: bool,

#[clap(from_global)]
quiet: bool,

#[clap(from_global)]
root: Option<PathBuf>,

Expand Down Expand Up @@ -105,8 +102,8 @@ impl OroCommand for RestoreCmd {
if !self.lockfile_only {
self.prune(&emoji, &resolved_nm).await?;
self.extract(&emoji, &resolved_nm).await?;
} else if !self.quiet {
eprintln!(
} else {
tracing::info!(
"{}Skipping prune and extract, only writing lockfile",
emoji.package()
);
Expand All @@ -116,18 +113,14 @@ impl OroCommand for RestoreCmd {
.write_lockfile(root.join("package-lock.kdl"))
.await?;

if !self.quiet {
eprintln!("{}Wrote lockfile to package-lock.kdl.", emoji.writing());
}
tracing::info!("{}Wrote lockfile to package-lock.kdl.", emoji.writing());

if !self.quiet {
eprintln!(
"{}Done in {}s. {}",
emoji.tada(),
total_time.elapsed().as_millis() as f32 / 1000.0,
hackerish_encouragement()
);
}
tracing::info!(
"{}Done in {}s. {}",
emoji.tada(),
total_time.elapsed().as_millis() as f32 / 1000.0,
hackerish_encouragement()
);
Ok(())
}
}
Expand All @@ -141,11 +134,11 @@ impl RestoreCmd {
) -> Result<NodeMaintainer> {
// Set up progress bar and timing stuff.
let resolve_time = std::time::Instant::now();
let resolve_span = tracing::info_span!("resolving");
let resolve_span = tracing::debug_span!("resolving");
resolve_span.pb_set_style(
&ProgressStyle::default_bar()
.template(&format!(
"{}{}",
"{}Resolving {}",
emoji.magnifying_glass(),
"{bar:40} [{pos}/{len}] {wide_msg:.dim}"
))
Expand All @@ -162,26 +155,24 @@ impl RestoreCmd {
// Wrap up progress bar and print messages.
std::mem::drop(resolve_span_enter);
std::mem::drop(resolve_span);
if !self.quiet {
eprintln!(
"{}Resolved {} packages in {}s.",
emoji.magnifying_glass(),
resolved_nm.package_count(),
resolve_time.elapsed().as_millis() as f32 / 1000.0
);
}
tracing::info!(
"{}Resolved {} packages in {}s.",
emoji.magnifying_glass(),
resolved_nm.package_count(),
resolve_time.elapsed().as_millis() as f32 / 1000.0
);

Ok(resolved_nm)
}

async fn prune(&self, emoji: &Emoji, maintainer: &NodeMaintainer) -> Result<()> {
// Set up progress bar and timing stuff.
let prune_time = std::time::Instant::now();
let prune_span = tracing::info_span!("prune");
let prune_span = tracing::debug_span!("prune");
prune_span.pb_set_style(
&ProgressStyle::default_bar()
.template(&format!(
"{}{}",
"{}Pruning extraneous {}",
emoji.broom(),
"{bar:40} [{pos}] {wide_msg:.dim}"
))
Expand All @@ -196,25 +187,23 @@ impl RestoreCmd {
// Wrap up progress bar and message.
std::mem::drop(prune_span_enter);
std::mem::drop(prune_span);
if !self.quiet {
eprintln!(
"{}Pruned {pruned} packages in {}s.",
emoji.broom(),
prune_time.elapsed().as_millis() as f32 / 1000.0
);
}
tracing::info!(
"{}Pruned {pruned} packages in {}s.",
emoji.broom(),
prune_time.elapsed().as_millis() as f32 / 1000.0
);

Ok(())
}

async fn extract(&self, emoji: &Emoji, maintainer: &NodeMaintainer) -> Result<()> {
// Set up progress bar and timing stuff.
let extract_time = std::time::Instant::now();
let extract_span = tracing::info_span!("extract");
let extract_span = tracing::debug_span!("extract");
extract_span.pb_set_style(
&ProgressStyle::default_bar()
.template(&format!(
"{}{}",
"{}Extracting {}",
emoji.package(),
"{bar:40} [{pos}/{len}] {wide_msg:.dim}"
))
Expand All @@ -229,14 +218,12 @@ impl RestoreCmd {
// Wrap up progress bar and message.
std::mem::drop(extract_span_enter);
std::mem::drop(extract_span);
if !self.quiet {
eprintln!(
"{}Extracted {extracted} package{} in {}s.",
emoji.package(),
if extracted == 1 { "" } else { "s" },
extract_time.elapsed().as_millis() as f32 / 1000.0
);
}
tracing::info!(
"{}Extracted {extracted} package{} in {}s.",
emoji.package(),
if extracted == 1 { "" } else { "s" },
extract_time.elapsed().as_millis() as f32 / 1000.0
);

Ok(())
}
Expand Down

0 comments on commit e1cafd0

Please sign in to comment.