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.

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

Fix stats report #2292

Merged
merged 2 commits into from
Nov 22, 2023
Merged

Fix stats report #2292

merged 2 commits into from
Nov 22, 2023

Conversation

digit-google
Copy link
Contributor

Fix two minor issues in the output of -d stats where things were not counted properly:

  • The node stat metric appeared twice with different values, which was a bit confusing :-)
  • The .ninja_parse value was double-counting the parsing time due to recursive manifest parser calls.

In short:

BEFORE:

metric                  count   avg (us)        total (ms)
.ninja parse            27304   372.6           10172.2
node stat               119145  2.9             340.7
node stat               270673  3.0             819.3
...

AFTER:

metric                  count   avg (us)        total (ms)
.ninja parse            1       4109354.0       4109.4
node stat               270673  2.9             774.0
...

@jhasse jhasse added this to the 1.12.0 milestone Apr 27, 2023
@digit-google
Copy link
Contributor Author

friendly ping

@digit-google
Copy link
Contributor Author

ping ?

Because Parser::Load() is called recursively during Ninja
manifest parsing, the call to METRIC_RECORD() in this function
used to over-count the total parsing time (for example, by a
factor of 2 for the Fuchsia build).

This fixes the problem by introducing a new RECORD_METRIC_IF()
macro, which only records anything if a given condition is true.
This ensures that metric collection only starts and stops with
the outer Parser::Load() call, and none of its recursive
sub-calls.

The effect on the output of `-d stats`is, for a Fuchsia build
plan where `ninja -d stats nothing` takes a bit more than 5s:

BEFORE:
  metric                  count   avg (us)        total (ms)
  .ninja parse            27304   372.6           10172.2

AFTER:
  metric                  count   avg (us)        total (ms)
  .ninja parse            1       4165297.0       4165.3

Note that |count| went to 1, since there is only one top-level
Parser::Load() operation in this build. It would be more if
dyndeps files were loaded, which does not happen in this
build plan.
This is already done in RealDiskInterface::Stat() itself,
and removes a confusing duplicate line in `-d stats` output,
e.g.:

BEFORE:
  metric                  count   avg (us)        total (ms)
  ...
  node stat               119145  3.0             355.2
  node stat               270673  3.1             834.9

AFTER:
  metric                  count   avg (us)        total (ms)
  ...
  node stat               270673  2.9             774.0
@jhasse jhasse merged commit 82a7cb3 into ninja-build:master Nov 22, 2023
9 checks passed
@jhasse
Copy link
Collaborator

jhasse commented Nov 22, 2023

Thanks!

@digit-google digit-google deleted the fix-stats-report branch January 11, 2024 17:44
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants