Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Update --timings=json output include data similar to the HTML output #10463

Closed
wants to merge 3 commits into from
Closed

Update --timings=json output include data similar to the HTML output #10463

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
687029b
impl Serialize for a few timing structs and move output to a file sim…
CraZySacX Mar 7, 2022
c9396db
removed unused code
CraZySacX Mar 7, 2022
b5e77df
cargo fmt
CraZySacX Mar 7, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
63 changes: 49 additions & 14 deletions src/cargo/core/compiler/timings.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -7,10 +7,10 @@ use crate::core::compiler::job_queue::JobId;
use crate::core::compiler::{BuildContext, Context, TimingOutput};
use crate::core::PackageId;
use crate::util::cpu::State;
use crate::util::machine_message::{self, Message};
use crate::util::{CargoResult, Config};
use anyhow::Context as _;
use cargo_util::paths;
use serde::{ser::SerializeStruct, Serialize, Serializer};
use std::collections::HashMap;
use std::io::{BufWriter, Write};
use std::thread::available_parallelism;
Expand Down Expand Up @@ -55,7 +55,26 @@ pub struct Timings<'cfg> {
cpu_usage: Vec<(f64, f64)>,
}

impl Serialize for Timings<'_> {
fn serialize<S>(&self, serializer: S) -> std::result::Result<S::Ok, S::Error>
where
S: Serializer,
{
let mut state = serializer.serialize_struct("Timings", 8)?;
state.serialize_field("duration", &self.start.elapsed().as_secs_f64())?;
state.serialize_field("root_tuples", &self.root_targets)?;
state.serialize_field("profile", &self.profile)?;
state.serialize_field("total_fresh", &self.total_fresh)?;
state.serialize_field("total_dirty", &self.total_dirty)?;
state.serialize_field("unit_times", &self.unit_times)?;
state.serialize_field("concurrency", &self.concurrency)?;
state.serialize_field("cpu_usage", &self.cpu_usage)?;
state.end()
}
}

/// Tracking information for an individual unit.
#[derive(Serialize)]
struct UnitTime {
unit: Unit,
/// A string describing the cargo target.
Expand All @@ -74,7 +93,7 @@ struct UnitTime {
}

/// Periodic concurrency tracking information.
#[derive(serde::Serialize)]
#[derive(Serialize)]
struct Concurrency {
/// Time as an offset in seconds from `Timings::start`.
t: f64,
Expand Down Expand Up @@ -218,17 +237,6 @@ impl<'cfg> Timings<'cfg> {
unit_time
.unlocked_units
.extend(unlocked.iter().cloned().cloned());
if self.report_json {
let msg = machine_message::TimingInfo {
package_id: unit_time.unit.pkg.package_id(),
target: &unit_time.unit.target,
mode: unit_time.unit.mode,
duration: unit_time.duration,
rmeta_time: unit_time.rmeta_time,
}
.to_json_string();
crate::drop_println!(self.config, "{}", msg);
}
self.unit_times.push(unit_time);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

There are some things that raise some flags for me

  • This moves away from serializing machine_message to internal data structures. Using code in machine_message helps raise awareness of the compatibility requirements when making changes and is more discoverable for people who want to parse the output
  • Generally we print messages as we go rather than doing one bug final message
  • The PR doesn't explain why some information was left out of the report for stablization

Overall, I'd recommend

  • Find out the thought process for what data got stablized
  • Create an issue for discussing stabilizing more information (Issues are much better for discussing requirements and design while PRs are much focusing on an implementation to resolve an Issue)
  • Focus on incrementally printing machine_message structs.

Copy link
Contributor Author

@CraZySacX CraZySacX Mar 18, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I can open an issue to discuss if you'd prefer, but I have a few question:

  • The HTML reporting uses internal data structures exclusively. The intent here was to emulate the HTML reporting. Are you suggesting that all of the reporting structs move to machine_message?
  • Capturing stdout output printed on the fly in a meaningful way is a bit cumbersome. Again, emulating the HTML reporting was a goal, so the larger final output at the end was used. Should we do both?
  • Forgot to mention that the data collected was mostly inline with that the HTML report collected. It does appear I missed a couple fields. Those should definitely be included.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Capturing stdout output printed on the fly in a meaningful way is a bit cumbersome. Again, emulating the HTML reporting was a goal, so the larger final output at the end was used. Should we do both?

Pretty much all cargo messages (except cargo metadata) communicate like this. libtet also works this way with providing suite summary messages in addition to the individual tests.

The HTML reporting uses internal data structures exclusively. The intent here was to emulate the HTML reporting. Are you suggesting that all of the reporting structs move to machine_message?

I can definitely understand this. I love the idea of a separating out the view and model like this. At times though, shortcuts are made because not everything is locked down yet. This is why I was recommending looking into and having a discussion on why not everything is exposed.

}

Expand Down Expand Up @@ -305,8 +313,35 @@ impl<'cfg> Timings<'cfg> {
.sort_unstable_by(|a, b| a.start.partial_cmp(&b.start).unwrap());
if self.report_html {
self.report_html(cx, error)
.with_context(|| "failed to save timing report")?;
.with_context(|| "failed to save html timing report")?;
}
if self.report_json {
self.report_json(cx)
.with_context(|| "failed to save json timing report")?;
}
Ok(())
}

/// Save JSON report to disk
fn report_json(&self, cx: &Context<'_, '_>) -> CargoResult<()> {
let timestamp = self.start_str.replace(&['-', ':'][..], "");
let timings_path = cx.files().host_root().join("cargo-timings");
paths::create_dir_all(&timings_path)?;
let filename = timings_path.join(format!("cargo-timing-{}.json", timestamp));
let mut f = BufWriter::new(paths::create(&filename)?);
f.write_all(serde_json::to_string(self)?.as_bytes())?;
let msg = format!(
"report saved to {}",
std::env::current_dir()
.unwrap_or_default()
.join(&filename)
.display()
);
let unstamped_filename = timings_path.join("cargo-timing.json");
paths::link_or_copy(&filename, &unstamped_filename)?;
self.config
.shell()
.status_with_color("Timing", msg, termcolor::Color::Cyan)?;
Ok(())
}

Expand Down
20 changes: 20 additions & 0 deletions src/cargo/core/compiler/unit.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ use crate::core::{profiles::Profile, Package};
use crate::util::hex::short_hash;
use crate::util::interning::InternedString;
use crate::util::Config;
use serde::{ser::SerializeStruct, Serialize, Serializer};
use std::cell::RefCell;
use std::collections::HashSet;
use std::fmt;
Expand Down Expand Up @@ -145,6 +146,25 @@ impl fmt::Debug for Unit {
}
}

impl Serialize for Unit {
fn serialize<S>(&self, serializer: S) -> std::result::Result<S::Ok, S::Error>
where
S: Serializer,
{
let mut state = serializer.serialize_struct("Unit", 9)?;
state.serialize_field("pkg_id", &self.pkg.package_id())?;
state.serialize_field("target", &self.target)?;
state.serialize_field("profile", &self.profile)?;
state.serialize_field("kind", &self.kind)?;
state.serialize_field("mode", &self.mode)?;
state.serialize_field("features", &self.features)?;
state.serialize_field("artifact", &self.artifact.is_true())?;
state.serialize_field("is_std", &self.is_std)?;
state.serialize_field("dep_hash", &self.dep_hash)?;
state.end()
}
}

/// A small structure used to "intern" `Unit` values.
///
/// A `Unit` is just a thin pointer to an internal `UnitInner`. This is done to
Expand Down
18 changes: 1 addition & 17 deletions src/cargo/util/machine_message.rs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,7 +4,7 @@ use serde::ser;
use serde::Serialize;
use serde_json::{self, json, value::RawValue};

use crate::core::{compiler::CompileMode, PackageId, Target};
use crate::core::{PackageId, Target};

pub trait Message: ser::Serialize {
fn reason(&self) -> &str;
Expand Down Expand Up @@ -77,22 +77,6 @@ impl<'a> Message for BuildScript<'a> {
}
}

#[derive(Serialize)]
pub struct TimingInfo<'a> {
pub package_id: PackageId,
pub target: &'a Target,
pub mode: CompileMode,
pub duration: f64,
#[serde(skip_serializing_if = "Option::is_none")]
pub rmeta_time: Option<f64>,
}

impl<'a> Message for TimingInfo<'a> {
fn reason(&self) -> &str {
"timing-info"
}
}

#[derive(Serialize)]
pub struct BuildFinished {
pub success: bool,
Expand Down