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

feat: stop printing unused syscalls in execution report #1787

Merged
merged 2 commits into from
Nov 13, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
74 changes: 52 additions & 22 deletions crates/core/executor/src/events/utils.rs
Original file line number Diff line number Diff line change
@@ -1,9 +1,6 @@
use serde::Deserialize;
use serde::Serialize;
use std::{
fmt::Display,
iter::{Map, Peekable},
};
use std::fmt::Display;

/// A unique identifier for lookups.
#[derive(Deserialize, Serialize, Debug, Clone, Copy, Default, Eq, Hash, PartialEq)]
Expand All @@ -17,32 +14,65 @@ pub(crate) fn create_random_lookup_ids() -> [LookupId; 6] {
std::array::from_fn(|_| LookupId(rand::random()))
}

/// Returns sorted and formatted rows of a table of counts (e.g. `opcode_counts`).
/// Returns a tuple containing everything needed to to correctly display a table of counts
/// (e.g. `opcode_counts`):
///
/// The table is sorted first by count (descending) and then by label (ascending).
/// The first column consists of the counts, is right-justified, and is padded precisely
/// enough to fit all the numbers. The second column consists of the labels (e.g. `OpCode`s).
/// The columns are separated by a single space character.
#[allow(clippy::type_complexity)]
/// 1. The number of characters of the highest count, that can be used to right-justify the count
/// column.
///
/// 2. The table sorted first by count (descending) and then by label (ascending). The table
/// itself is an iterator of a tuple (label, count).
pub fn sorted_table_lines<'a, K, V>(
table: impl IntoIterator<Item = (K, V)> + 'a,
) -> Map<
Peekable<Map<std::vec::IntoIter<(K, V)>, impl FnMut((K, V)) -> (String, String)>>,
impl FnMut((String, String)) -> String,
>
table: impl IntoIterator<Item = (K, &'a V)> + 'a,
) -> (usize, impl Iterator<Item = (String, &'a V)>)
where
K: Ord + Display + 'a,
V: Ord + Display + 'a,
{
let mut entries = table.into_iter().collect::<Vec<_>>();
// Sort table by count (descending), then the name order (ascending).
entries.sort_unstable_by(|a, b| a.1.cmp(&b.1).reverse().then_with(|| a.0.cmp(&b.0)));
entries.sort_unstable_by(|a, b| a.1.cmp(b.1).reverse().then_with(|| a.0.cmp(&b.0)));
// Convert counts to `String`s to prepare them for printing and to measure their width.
let mut table_with_string_counts = entries
.into_iter()
.map(|(label, ct)| (label.to_string().to_lowercase(), ct.to_string()))
.peekable();
let mut entries =
entries.into_iter().map(|(label, ct)| (label.to_string().to_lowercase(), ct)).peekable();
// Calculate width for padding the counts.
let width = table_with_string_counts.peek().map(|(_, b)| b.len()).unwrap_or_default();
table_with_string_counts.map(move |(label, count)| format!("{count:>width$} {label}"))
let width = entries.peek().map(|(_, b)| b.to_string().len()).unwrap_or_default();

(width, entries)
}

/// Returns a formatted row of a table of counts (e.g. `opcode_counts`).
///
/// The first column consists of the counts, is right-justified, and is padded precisely
/// enough to fit all the numbers, using the provided `width`. The second column consists of
/// the labels (e.g. `OpCode`s). The columns are separated by a single space character.
#[must_use]
pub fn format_table_line<V>(width: &usize, label: &str, count: &V) -> String
where
V: Display,
{
format!("{count:>width$} {label}")
}

/// Returns sorted and formatted rows of a table of counts (e.g. `opcode_counts`).
///
/// The table is sorted first by count (descending) and then by label (ascending).
/// The first column consists of the counts, is right-justified, and is padded precisely
/// enough to fit all the numbers. The second column consists of the labels (e.g. `OpCode`s).
/// The columns are separated by a single space character.
///
/// It's possible to hide rows with 0 count by setting `hide_zeros` to true.
pub fn generate_execution_report<'a, K, V>(
table: impl IntoIterator<Item = (K, &'a V)> + 'a,
hide_zeros: bool,
) -> impl Iterator<Item = String> + 'a
where
K: Ord + Display + 'a,
V: Ord + PartialEq<u64> + Display + 'a,
{
let (width, lines) = sorted_table_lines(table);

lines
.filter(move |(_, count)| !hide_zeros || **count != 0_u64)
.map(move |(label, count)| format!(" {}", format_table_line(&width, &label, count)))
}
6 changes: 3 additions & 3 deletions crates/core/executor/src/report.rs
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,7 @@ use std::{
use enum_map::{EnumArray, EnumMap};
use hashbrown::HashMap;

use crate::{events::sorted_table_lines, syscalls::SyscallCode, Opcode};
use crate::{events::generate_execution_report, syscalls::SyscallCode, Opcode};

/// An execution report.
#[derive(Default, Debug, Clone, PartialEq, Eq)]
Expand Down Expand Up @@ -68,12 +68,12 @@ impl Add for ExecutionReport {
impl Display for ExecutionReport {
fn fmt(&self, f: &mut Formatter<'_>) -> FmtResult {
writeln!(f, "opcode counts ({} total instructions):", self.total_instruction_count())?;
for line in sorted_table_lines(self.opcode_counts.as_ref()) {
for line in generate_execution_report(self.opcode_counts.as_ref(), false) {
writeln!(f, " {line}")?;
}

writeln!(f, "syscall counts ({} total syscall instructions):", self.total_syscall_count())?;
for line in sorted_table_lines(self.syscall_counts.as_ref()) {
for line in generate_execution_report(self.syscall_counts.as_ref(), true) {
writeln!(f, " {line}")?;
}

Expand Down
7 changes: 4 additions & 3 deletions crates/core/machine/src/utils/prove.rs
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ use crate::{
riscv::cost::CostEstimator,
utils::{chunk_vec, concurrency::TurnBasedSync},
};
use sp1_core_executor::{events::sorted_table_lines, ExecutionState};
use sp1_core_executor::{events::generate_execution_report, ExecutionState};
use sp1_primitives::io::SP1PublicValues;

use sp1_core_executor::{
Expand Down Expand Up @@ -674,11 +674,12 @@ where
// Print the opcode and syscall count tables like `du`: sorted by count (descending) and
// with the count in the first column.
tracing::info!("execution report (opcode counts):");
for line in sorted_table_lines(report_aggregate.opcode_counts.as_ref()) {
for line in generate_execution_report(report_aggregate.opcode_counts.as_ref(), false) {
tracing::info!(" {line}");
}

tracing::info!("execution report (syscall counts):");
for line in sorted_table_lines(report_aggregate.syscall_counts.as_ref()) {
for line in generate_execution_report(report_aggregate.syscall_counts.as_ref(), true) {
tracing::info!(" {line}");
}

Expand Down
6 changes: 4 additions & 2 deletions crates/core/machine/src/utils/span.rs
Original file line number Diff line number Diff line change
@@ -1,6 +1,6 @@
use std::{collections::HashMap, fmt::Display, hash::Hash, iter::once};

use sp1_core_executor::events::sorted_table_lines;
use sp1_core_executor::events::{format_table_line, sorted_table_lines};
use thiserror::Error;

/// A builder to create a [`Span`].
Expand Down Expand Up @@ -116,13 +116,15 @@ where
/// Format and yield lines describing this span. Appropriate for logging.
pub fn lines(&self) -> Vec<String> {
let Self { name, cts: instr_cts, children } = self;
let (width, lines) = sorted_table_lines(instr_cts);
let lines = lines.map(|(label, count)| format_table_line(&width, &label, count));

once(format!("{}", name))
.chain(
children
.iter()
.flat_map(|c| c.lines())
.chain(sorted_table_lines(instr_cts))
.chain(lines)
.map(|line| format!("│ {line}")),
)
.chain(once(format!("└╴ {} total", self.total())))
Expand Down
Loading