diff --git a/crates/aiken-lang/src/test_framework.rs b/crates/aiken-lang/src/test_framework.rs index 57ba0491..e5bc05d1 100644 --- a/crates/aiken-lang/src/test_framework.rs +++ b/crates/aiken-lang/src/test_framework.rs @@ -231,17 +231,17 @@ impl UnitTest { OnTestFailure::FailImmediately => false, }); - let mut traces = Vec::new(); + let mut logs = Vec::new(); if let Err(err) = eval_result.result() { - traces.push(format!("{err}")) + logs.push(format!("{err}")) } - traces.extend(eval_result.logs()); + logs.extend(eval_result.logs()); UnitTestResult { success, test: self.to_owned(), spent_budget: eval_result.cost(), - traces, + logs, assertion: self.assertion, } } @@ -276,7 +276,7 @@ pub struct Fuzzer { #[derive(Debug, Clone, thiserror::Error, miette::Diagnostic)] #[error("Fuzzer exited unexpectedly: {uplc_error}.")] pub struct FuzzerError { - traces: Vec, + logs: Vec, uplc_error: uplc::machine::Error, } @@ -330,7 +330,7 @@ impl PropertyTest { let mut labels = BTreeMap::new(); let mut remaining = n; - let (traces, counterexample, iterations) = match self.run_n_times( + let (logs, counterexample, iterations) = match self.run_n_times( &mut remaining, Prng::from_seed(seed), &mut labels, @@ -339,18 +339,12 @@ impl PropertyTest { Ok(None) => (Vec::new(), Ok(None), n), Ok(Some(counterexample)) => ( self.eval(&counterexample.value, plutus_version) - .logs() - .into_iter() - .filter(|s| PropertyTest::extract_label(s).is_none()) - .collect(), + .logs(), Ok(Some(counterexample.value)), n - remaining, ), - Err(FuzzerError { traces, uplc_error }) => ( - traces - .into_iter() - .filter(|s| PropertyTest::extract_label(s).is_none()) - .collect(), + Err(FuzzerError { logs, uplc_error }) => ( + logs, Err(uplc_error), n - remaining + 1, ), @@ -361,7 +355,7 @@ impl PropertyTest { counterexample, iterations, labels, - traces, + logs, } } @@ -397,16 +391,14 @@ impl PropertyTest { let mut result = self.eval(&value, plutus_version); - for s in result.logs() { + for label in result.labels() { // NOTE: There may be other log outputs that interefere with labels. So *by // convention*, we treat as label strings that starts with a NUL byte, which // should be a guard sufficient to prevent inadvertent clashes. - if let Some(label) = PropertyTest::extract_label(&s) { - labels - .entry(label) - .and_modify(|count| *count += 1) - .or_insert(1); - } + labels + .entry(label) + .and_modify(|count| *count += 1) + .or_insert(1); } let is_failure = result.failed(false); @@ -470,14 +462,6 @@ impl PropertyTest { .unwrap() .eval_version(ExBudget::max(), &plutus_version.into()) } - - fn extract_label(s: &str) -> Option { - if s.starts_with('\0') { - Some(s.split_at(1).1.to_string()) - } else { - None - } - } } /// ----- Benchmark ----------------------------------------------------------------- @@ -498,21 +482,21 @@ pub struct Sampler { pub enum BenchmarkError { #[error("Sampler exited unexpectedly: {uplc_error}.")] SamplerError { - traces: Vec, + logs: Vec, uplc_error: uplc::machine::Error, }, #[error("Bench exited unexpectedly: {uplc_error}.")] BenchError { - traces: Vec, + logs: Vec, uplc_error: uplc::machine::Error, }, } impl BenchmarkError { - pub fn traces(&self) -> &[String] { + pub fn logs(&self) -> &[String] { match self { - BenchmarkError::SamplerError { traces, .. } - | BenchmarkError::BenchError { traces, .. } => traces.as_slice(), + BenchmarkError::SamplerError { logs, .. } + | BenchmarkError::BenchError { logs, .. } => logs.as_slice(), } } } @@ -561,19 +545,15 @@ impl Benchmark { Ok(_) => measures.push((size, result.cost())), Err(uplc_error) => { error = Some(BenchmarkError::BenchError { - traces: result - .logs() - .into_iter() - .filter(|s| PropertyTest::extract_label(s).is_none()) - .collect(), + logs: result.logs(), uplc_error, }); } } } - Err(FuzzerError { traces, uplc_error }) => { - error = Some(BenchmarkError::SamplerError { traces, uplc_error }); + Err(FuzzerError { logs, uplc_error }) => { + error = Some(BenchmarkError::SamplerError { logs, uplc_error }); } } @@ -692,7 +672,7 @@ impl Prng { result .result() .map_err(|uplc_error| FuzzerError { - traces: result.logs(), + logs: result.logs(), uplc_error, }) .map(Prng::from_result) @@ -1166,12 +1146,12 @@ impl TestResult { } } - pub fn traces(&self) -> &[String] { + pub fn logs(&self) -> &[String] { match self { - TestResult::UnitTestResult(UnitTestResult { traces, .. }) - | TestResult::PropertyTestResult(PropertyTestResult { traces, .. }) => traces, + TestResult::UnitTestResult(UnitTestResult { logs, .. }) + | TestResult::PropertyTestResult(PropertyTestResult { logs, .. }) => logs, TestResult::BenchmarkResult(BenchmarkResult { error, .. }) => { - error.as_ref().map(|e| e.traces()).unwrap_or_default() + error.as_ref().map(|e| e.logs()).unwrap_or_default() } } } @@ -1181,7 +1161,7 @@ impl TestResult { pub struct UnitTestResult { pub success: bool, pub spent_budget: ExBudget, - pub traces: Vec, + pub logs: Vec, pub test: UnitTest, pub assertion: Option>, } @@ -1196,7 +1176,7 @@ impl UnitTestResult<(Constant, Rc)> { UnitTestResult { success: self.success, spent_budget: self.spent_budget, - traces: self.traces, + logs: self.logs, test: self.test, assertion: self.assertion.and_then(|assertion| { // No need to spend time/cpu on reifying assertions for successful @@ -1229,7 +1209,7 @@ pub struct PropertyTestResult { pub counterexample: Result, uplc::machine::Error>, pub iterations: usize, pub labels: BTreeMap, - pub traces: Vec, + pub logs: Vec, } unsafe impl Send for PropertyTestResult {} @@ -1249,7 +1229,7 @@ impl PropertyTestResult { iterations: self.iterations, test: self.test, labels: self.labels, - traces: self.traces, + logs: self.logs, } } } diff --git a/crates/aiken-project/src/telemetry/json.rs b/crates/aiken-project/src/telemetry/json.rs index f2f0893b..8a892b0b 100644 --- a/crates/aiken-project/src/telemetry/json.rs +++ b/crates/aiken-project/src/telemetry/json.rs @@ -129,8 +129,8 @@ fn fmt_test_json(result: &TestResult) -> serde_json::V TestResult::BenchmarkResult(_) => unreachable!("benchmark returned in JSON output"), } - if !result.traces().is_empty() { - test["traces"] = json!(result.traces()); + if !result.logs().is_empty() { + test["traces"] = json!(result.logs()); } test diff --git a/crates/aiken-project/src/telemetry/terminal.rs b/crates/aiken-project/src/telemetry/terminal.rs index 2be6bc52..83015d93 100644 --- a/crates/aiken-project/src/telemetry/terminal.rs +++ b/crates/aiken-project/src/telemetry/terminal.rs @@ -584,12 +584,12 @@ fn fmt_test( } // Traces - if !result.traces().is_empty() { + if !result.logs().is_empty() { test = format!( "{test}\n{title}\n{traces}", title = "ยท with traces".if_supports_color(Stderr, |s| s.bold()), traces = result - .traces() + .logs() .iter() .map(|line| { format!("| {line}",) }) .collect::>() diff --git a/crates/aiken/src/cmd/tx/simulate.rs b/crates/aiken/src/cmd/tx/simulate.rs index d89e7b00..142b5d05 100644 --- a/crates/aiken/src/cmd/tx/simulate.rs +++ b/crates/aiken/src/cmd/tx/simulate.rs @@ -137,7 +137,7 @@ pub fn exec( // this should allow N scripts to be let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) diff --git a/crates/uplc/src/ast.rs b/crates/uplc/src/ast.rs index 87f12fae..e1b623d4 100644 --- a/crates/uplc/src/ast.rs +++ b/crates/uplc/src/ast.rs @@ -856,7 +856,7 @@ impl Program { term, machine.ex_budget, initial_budget, - machine.logs, + machine.traces, machine.spend_counter.map(|i| i.into()), ) } @@ -871,7 +871,7 @@ impl Program { term, machine.ex_budget, initial_budget, - machine.logs, + machine.traces, machine.spend_counter.map(|i| i.into()), ) } @@ -897,7 +897,7 @@ impl Program { term, machine.ex_budget, budget, - machine.logs, + machine.traces, machine.spend_counter.map(|i| i.into()), ) } @@ -916,7 +916,7 @@ impl Program { term, machine.ex_budget, initial_budget, - machine.logs, + machine.traces, machine.spend_counter.map(|i| i.into()), ) } diff --git a/crates/uplc/src/machine.rs b/crates/uplc/src/machine.rs index 2d19a854..c976bbb0 100644 --- a/crates/uplc/src/machine.rs +++ b/crates/uplc/src/machine.rs @@ -45,13 +45,42 @@ enum Context { pub const TERM_COUNT: usize = 9; pub const BUILTIN_COUNT: usize = 87; +#[derive(Debug, Clone)] +pub enum Trace { + Log(String), + Label(String), +} + +impl Trace { + pub fn to_string(&self) -> String { + match self { + Trace::Log(log) => log.clone(), + Trace::Label(label) => label.clone(), + } + } + + pub fn unwrap_log(self) -> Option { + match self { + Trace::Log(log) => Some(log), + _ => None, + } + } + + pub fn unwrap_label(self) -> Option { + match self { + Trace::Label(label) => Some(label), + _ => None, + } + } +} + pub struct Machine { costs: CostModel, pub ex_budget: ExBudget, slippage: u32, unbudgeted_steps: [u32; 10], + pub traces: Vec, pub spend_counter: Option<[i64; (TERM_COUNT + BUILTIN_COUNT) * 2]>, - pub logs: Vec, version: Language, } @@ -67,8 +96,8 @@ impl Machine { ex_budget: initial_budget, slippage, unbudgeted_steps: [0; 10], + traces: vec![], spend_counter: None, - logs: vec![], version, } } @@ -84,8 +113,8 @@ impl Machine { ex_budget: initial_budget, slippage, unbudgeted_steps: [0; 10], + traces: vec![], spend_counter: Some([0; (TERM_COUNT + BUILTIN_COUNT) * 2]), - logs: vec![], version, } } @@ -353,7 +382,7 @@ impl Machine { counter[i + 1] += cost.cpu; } - runtime.call(&self.version, &mut self.logs) + runtime.call(&self.version, &mut self.traces) } fn lookup_var(&mut self, name: &NamedDeBruijn, env: &[Value]) -> Result { diff --git a/crates/uplc/src/machine/eval_result.rs b/crates/uplc/src/machine/eval_result.rs index 58043220..9fbddceb 100644 --- a/crates/uplc/src/machine/eval_result.rs +++ b/crates/uplc/src/machine/eval_result.rs @@ -1,4 +1,4 @@ -use super::{cost_model::ExBudget, Error}; +use super::{cost_model::ExBudget, Error, Trace}; use crate::ast::{Constant, NamedDeBruijn, Term}; #[derive(Debug)] @@ -6,7 +6,7 @@ pub struct EvalResult { result: Result, Error>, remaining_budget: ExBudget, initial_budget: ExBudget, - logs: Vec, + traces: Vec, debug_cost: Option>, } @@ -15,14 +15,14 @@ impl EvalResult { result: Result, Error>, remaining_budget: ExBudget, initial_budget: ExBudget, - logs: Vec, + traces: Vec, debug_cost: Option>, ) -> EvalResult { EvalResult { result, remaining_budget, initial_budget, - logs, + traces, debug_cost, } } @@ -31,8 +31,22 @@ impl EvalResult { self.initial_budget - self.remaining_budget } + pub fn traces(&mut self) -> Vec { + std::mem::take(&mut self.traces) + } + pub fn logs(&mut self) -> Vec { - std::mem::take(&mut self.logs) + std::mem::take(&mut self.traces) + .into_iter() + .filter_map(Trace::unwrap_log) + .collect() + } + + pub fn labels(&mut self) -> Vec { + std::mem::take(&mut self.traces) + .into_iter() + .filter_map(Trace::unwrap_label) + .collect() } pub fn failed(&self, can_error: bool) -> bool { diff --git a/crates/uplc/src/machine/runtime.rs b/crates/uplc/src/machine/runtime.rs index c55dd859..823069f6 100644 --- a/crates/uplc/src/machine/runtime.rs +++ b/crates/uplc/src/machine/runtime.rs @@ -1,7 +1,5 @@ use super::{ - cost_model::{BuiltinCosts, ExBudget}, - value::{from_pallas_bigint, to_pallas_bigint}, - Error, Value, + cost_model::{BuiltinCosts, ExBudget}, value::{from_pallas_bigint, to_pallas_bigint}, Error, Trace, Value }; use crate::{ ast::{Constant, Data, Type}, @@ -82,8 +80,8 @@ impl BuiltinRuntime { self.forces += 1; } - pub fn call(&self, language: &Language, logs: &mut Vec) -> Result { - self.fun.call(language.into(), &self.args, logs) + pub fn call(&self, language: &Language, traces: &mut Vec) -> Result { + self.fun.call(language.into(), &self.args, traces) } pub fn push(&mut self, arg: Value) -> Result<(), Error> { @@ -388,7 +386,7 @@ impl DefaultFunction { &self, semantics: BuiltinSemantics, args: &[Value], - logs: &mut Vec, + traces: &mut Vec, ) -> Result { match self { DefaultFunction::AddInteger => { @@ -777,7 +775,11 @@ impl DefaultFunction { DefaultFunction::Trace => { let arg1 = args[0].unwrap_string()?; - logs.push(arg1.clone()); + if arg1.starts_with('\0') { + traces.push(Trace::Label(arg1.split_at(1).1.to_string())); + } else { + traces.push(Trace::Log(arg1.clone())); + } Ok(args[1].clone()) } diff --git a/crates/uplc/src/tx.rs b/crates/uplc/src/tx.rs index bb790d2b..69d76a2e 100644 --- a/crates/uplc/src/tx.rs +++ b/crates/uplc/src/tx.rs @@ -1,6 +1,6 @@ use crate::{ ast::{DeBruijn, Program}, - machine::cost_model::ExBudget, + machine::{cost_model::ExBudget, eval_result::EvalResult}, PlutusData, }; use error::Error; @@ -36,7 +36,7 @@ pub fn eval_phase_two( slot_config: &SlotConfig, run_phase_one: bool, with_redeemer: fn(&Redeemer) -> (), -) -> Result, Error> { +) -> Result, Error> { let redeemers = tx.transaction_witness_set.redeemer.as_ref(); let lookup_table = DataLookupTable::from_transaction(tx, utxos); @@ -48,7 +48,7 @@ pub fn eval_phase_two( match redeemers { Some(rs) => { - let mut collected_redeemers = vec![]; + let mut collected_results = vec![]; let mut remaining_budget = *initial_budget.unwrap_or(&ExBudget::default()); @@ -62,7 +62,7 @@ pub fn eval_phase_two( with_redeemer(&redeemer); - let redeemer = eval::eval_redeemer( + let (redeemer, eval_result) = eval::eval_redeemer( tx, utxos, slot_config, @@ -77,10 +77,10 @@ pub fn eval_phase_two( remaining_budget.cpu -= redeemer.ex_units.steps as i64; remaining_budget.mem -= redeemer.ex_units.mem as i64; - collected_redeemers.push(redeemer) + collected_results.push((redeemer, eval_result)); } - Ok(collected_redeemers) + Ok(collected_results) } None => Ok(vec![]), } @@ -98,7 +98,7 @@ pub fn eval_phase_two_raw( slot_config: (u64, u64, u32), run_phase_one: bool, with_redeemer: fn(&Redeemer) -> (), -) -> Result>, Error> { +) -> Result, EvalResult)>, Error> { let multi_era_tx = MultiEraTx::decode_for_era(Era::Conway, tx_bytes) .or_else(|e| MultiEraTx::decode_for_era(Era::Babbage, tx_bytes).map_err(|_| e)) .or_else(|e| MultiEraTx::decode_for_era(Era::Alonzo, tx_bytes).map_err(|_| e))?; @@ -139,8 +139,8 @@ pub fn eval_phase_two_raw( with_redeemer, ) { Ok(redeemers) => Ok(redeemers - .iter() - .map(|r| r.encode_fragment().unwrap()) + .into_iter() + .map(|(r, e)| (r.encode_fragment().unwrap(), e)) .collect()), Err(err) => Err(err), } diff --git a/crates/uplc/src/tx/error.rs b/crates/uplc/src/tx/error.rs index 17308fa1..61622f17 100644 --- a/crates/uplc/src/tx/error.rs +++ b/crates/uplc/src/tx/error.rs @@ -1,5 +1,5 @@ use crate::{ - machine::{self, cost_model::ExBudget}, + machine::{self, cost_model::ExBudget, Trace}, TransactionInput, }; use pallas_primitives::conway::Language; @@ -15,6 +15,7 @@ pub enum Error { #[error("{0}")] FragmentDecode(#[from] pallas_primitives::Error), #[error("{}{}", .0, .2.iter() + .map(|trace| trace.to_string()) .map(|trace| { format!( "\n{:>13} {}", @@ -42,7 +43,7 @@ pub enum Error { .join("") .as_str() )] - Machine(machine::Error, ExBudget, Vec), + Machine(machine::Error, ExBudget, Vec), #[error("native script can't be executed in phase-two")] NativeScriptPhaseTwo, diff --git a/crates/uplc/src/tx/eval.rs b/crates/uplc/src/tx/eval.rs index f9adf3b2..b1259d9c 100644 --- a/crates/uplc/src/tx/eval.rs +++ b/crates/uplc/src/tx/eval.rs @@ -5,7 +5,7 @@ use super::{ }; use crate::{ ast::{FakeNamedDeBruijn, NamedDeBruijn, Program}, - machine::cost_model::ExBudget, + machine::{cost_model::ExBudget, eval_result::EvalResult}, tx::{ phase_one::redeemer_tag_to_string, script_context::{DataLookupTable, ScriptVersion, TxInfoV1, TxInfoV2, TxInfoV3}, @@ -23,7 +23,7 @@ pub fn eval_redeemer( lookup_table: &DataLookupTable, cost_mdls_opt: Option<&CostModels>, initial_budget: &ExBudget, -) -> Result { +) -> Result<(Redeemer, EvalResult), Error> { fn do_eval_redeemer( cost_mdl_opt: Option<&CostModel>, initial_budget: &ExBudget, @@ -32,7 +32,7 @@ pub fn eval_redeemer( redeemer: &Redeemer, tx_info: TxInfo, program: Program, - ) -> Result { + ) -> Result<(Redeemer, EvalResult), Error> { let script_context = tx_info .into_script_context(redeemer, datum.as_ref()) .expect("couldn't create script context from transaction?"); @@ -56,11 +56,9 @@ pub fn eval_redeemer( }; let cost = eval_result.cost(); - let logs = eval_result.logs(); - match eval_result.result() { - Ok(_) => (), - Err(err) => return Err(Error::Machine(err, cost, logs)), + if let Err(err) = eval_result.result() { + return Err(Error::Machine(err, cost, eval_result.traces())); } let new_redeemer = Redeemer { @@ -73,7 +71,7 @@ pub fn eval_redeemer( }, }; - Ok(new_redeemer) + Ok((new_redeemer, eval_result)) } let program = |script: Bytes| { diff --git a/crates/uplc/src/tx/tests.rs b/crates/uplc/src/tx/tests.rs index d239fb6f..40a83397 100644 --- a/crates/uplc/src/tx/tests.rs +++ b/crates/uplc/src/tx/tests.rs @@ -254,7 +254,7 @@ fn test_eval_0() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -527,7 +527,7 @@ fn test_eval_1() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -638,7 +638,7 @@ fn test_eval_2() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -908,7 +908,7 @@ fn test_eval_3() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -1101,7 +1101,7 @@ fn test_eval_5() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -1211,7 +1211,7 @@ fn test_eval_6() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -1321,7 +1321,7 @@ fn test_eval_7() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, }) @@ -1582,7 +1582,7 @@ fn test_eval_8() { let total_budget_used: Vec = redeemers .iter() - .map(|curr| ExBudget { + .map(|(curr, _)| ExBudget { mem: curr.ex_units.mem as i64, cpu: curr.ex_units.steps as i64, })