Skip to content

Commit

Permalink
feat: stop printing unused syscalls in execution report (#1787)
Browse files Browse the repository at this point in the history
  • Loading branch information
leruaa authored Nov 13, 2024
1 parent 0c08caf commit 588286b
Show file tree
Hide file tree
Showing 4 changed files with 63 additions and 30 deletions.
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

0 comments on commit 588286b

Please sign in to comment.