aljaz/turso
1
0
Fork 0
mirror of https://github.com/aljazceru/turso.git synced 2026-02-13 20:24:18 +01:00
Code Issues Packages Projects Releases Wiki Activity

Merge 'simulator: switch to tracing, run io.run_once and add update queries' from Pere Diaz Bou

Browse Source 
* Without tracing crate we cannot log anything that happens in
limbo_core
* IO never ran in step loop inside simulator.
* Added update queries (which currently loop forever for some reason I'm
debugging).

Reviewed-by: Jussi Saurio <jussi.saurio@gmail.com>

Closes #1627
This commit is contained in:
Pekka Enberg
2025-05-30 12:52:34 +03:00
parent aa637d5ae1 8ee7228c43
commit 0fbff54b90
16 changed files with 253 additions and 98 deletions
Download Patch File Download Diff File Expand all files Collapse all files

2
Cargo.lock generated
View File

@@ -1968,6 +1968,8 @@ dependencies = [
"rusqlite",
"serde",
"serde_json",
"tracing",
"tracing-subscriber",
]
[[package]]

3
simulator/Cargo.toml
View File

@@ -32,3 +32,6 @@ notify = "8.0.0"
rusqlite = { version = "0.34", features = ["bundled"] }
dirs = "6.0.0"
chrono = { version = "0.4.40", features = ["serde"] }
tracing = "0.1.41"
tracing-subscriber = { version = "0.3.19", features = ["env-filter"] }

36
simulator/generation/plan.rs
View File

@@ -1,17 +1,18 @@
use std::{fmt::Display, path::Path, rc::Rc, vec};
use limbo_core::{Connection, Result, StepResult};
use limbo_core::{Connection, Result, StepResult, IO};
use serde::{Deserialize, Serialize};
use crate::{
model::{
query::{
select::{Distinctness, Predicate, ResultColumn},
update::Update,
Create, Delete, Drop, Insert, Query, Select,
},
table::Value,
},
runner::env::SimConnection,
runner::{env::SimConnection, io::SimulatorIO},
SimulatorEnv,
};
@@ -202,6 +203,7 @@ pub(crate) struct InteractionStats {
pub(crate) read_count: usize,
pub(crate) write_count: usize,
pub(crate) delete_count: usize,
pub(crate) update_count: usize,
pub(crate) create_count: usize,
pub(crate) drop_count: usize,
}
@@ -210,10 +212,11 @@ impl Display for InteractionStats {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(
f,
"Read: {}, Write: {}, Delete: {}, Create: {}, Drop: {}",
"Read: {}, Write: {}, Delete: {}, Update: {}, Create: {}, Drop: {}",
self.read_count,
self.write_count,
self.delete_count,
self.update_count,
self.create_count,
self.drop_count
)
@@ -369,6 +372,9 @@ impl Interactions {
Query::Select(select) => {
select.shadow(env);
}
Query::Update(update) => {
update.shadow(env);
}
},
Interaction::Assertion(_) => {}
Interaction::Assumption(_) => {}
@@ -395,6 +401,7 @@ impl InteractionPlan {
let mut delete = 0;
let mut create = 0;
let mut drop = 0;
let mut update = 0;
for interactions in &self.plan {
match interactions {
@@ -407,6 +414,7 @@ impl InteractionPlan {
Query::Delete(_) => delete += 1,
Query::Create(_) => create += 1,
Query::Drop(_) => drop += 1,
Query::Update(_) => update += 1,
}
}
}
@@ -417,6 +425,7 @@ impl InteractionPlan {
Query::Delete(_) => delete += 1,
Query::Create(_) => create += 1,
Query::Drop(_) => drop += 1,
Query::Update(_) => update += 1,
},
Interactions::Fault(_) => {}
}
@@ -428,6 +437,7 @@ impl InteractionPlan {
delete_count: delete,
create_count: create,
drop_count: drop,
update_count: update,
}
}
}
@@ -446,7 +456,7 @@ impl ArbitraryFrom<&mut SimulatorEnv> for InteractionPlan {
.push(Interactions::Query(Query::Create(create_query)));
while plan.plan.len() < num_interactions {
log::debug!(
tracing::debug!(
"Generating interaction {}/{}",
plan.plan.len(),
num_interactions
@@ -457,7 +467,7 @@ impl ArbitraryFrom<&mut SimulatorEnv> for InteractionPlan {
plan.plan.push(interactions);
}
log::info!("Generated plan with {} interactions", plan.plan.len());
tracing::info!("Generated plan with {} interactions", plan.plan.len());
plan
}
}
@@ -469,13 +479,13 @@ impl Interaction {
Self::Assumption(_) | Self::Assertion(_) | Self::Fault(_) => vec![],
}
}
pub(crate) fn execute_query(&self, conn: &mut Rc<Connection>) -> ResultSet {
pub(crate) fn execute_query(&self, conn: &mut Rc<Connection>, io: &SimulatorIO) -> ResultSet {
if let Self::Query(query) = self {
let query_str = query.to_string();
let rows = conn.query(&query_str);
if rows.is_err() {
let err = rows.err();
log::debug!(
tracing::debug!(
"Error running query '{}': {:?}",
&query_str[0..query_str.len().min(4096)],
err
@@ -503,7 +513,9 @@ impl Interaction {
}
out.push(r);
}
StepResult::IO => {}
StepResult::IO => {
io.run_once().unwrap();
}
StepResult::Interrupt => {}
StepResult::Done => {
break;
@@ -626,6 +638,10 @@ fn random_delete<R: rand::Rng>(rng: &mut R, env: &SimulatorEnv) -> Interactions
Interactions::Query(Query::Delete(Delete::arbitrary_from(rng, env)))
}
fn random_update<R: rand::Rng>(rng: &mut R, env: &SimulatorEnv) -> Interactions {
Interactions::Query(Query::Update(Update::arbitrary_from(rng, env)))
}
fn random_drop<R: rand::Rng>(rng: &mut R, env: &SimulatorEnv) -> Interactions {
Interactions::Query(Query::Drop(Drop::arbitrary_from(rng, env)))
}
@@ -664,6 +680,10 @@ impl ArbitraryFrom<(&SimulatorEnv, InteractionStats)> for Interactions {
remaining_.delete,
Box::new(|rng: &mut R| random_delete(rng, env)),
),
(
remaining_.update,
Box::new(|rng: &mut R| random_update(rng, env)),
),
(
// remaining_.drop,
0.0,

5
simulator/generation/property.rs
View File

@@ -444,6 +444,7 @@ pub(crate) struct Remaining {
pub(crate) write: f64,
pub(crate) create: f64,
pub(crate) delete: f64,
pub(crate) update: f64,
pub(crate) drop: f64,
}
@@ -460,6 +461,9 @@ pub(crate) fn remaining(env: &SimulatorEnv, stats: &InteractionStats) -> Remaini
let remaining_delete = ((env.opts.max_interactions as f64 * env.opts.delete_percent / 100.0)
- (stats.delete_count as f64))
.max(0.0);
let remaining_update = ((env.opts.max_interactions as f64 * env.opts.delete_percent / 100.0)
- (stats.update_count as f64))
.max(0.0);
let remaining_drop = ((env.opts.max_interactions as f64 * env.opts.drop_percent / 100.0)
- (stats.drop_count as f64))
.max(0.0);
@@ -470,6 +474,7 @@ pub(crate) fn remaining(env: &SimulatorEnv, stats: &InteractionStats) -> Remaini
create: remaining_create,
delete: remaining_delete,
drop: remaining_drop,
update: remaining_update,
}
}

32
simulator/generation/query.rs
View File

@@ -1,7 +1,10 @@
use std::collections::HashSet;
use crate::generation::table::{GTValue, LTValue};
use crate::generation::{one_of, Arbitrary, ArbitraryFrom};
use crate::model::query::select::{Distinctness, Predicate, ResultColumn};
use crate::model::query::update::Update;
use crate::model::query::{Create, Delete, Drop, Insert, Query, Select};
use crate::model::table::{Table, Value};
use crate::SimulatorEnv;
@@ -469,3 +472,32 @@ impl ArbitraryFrom<(&Table, &Vec<Value>)> for Predicate {
result
}
}
impl ArbitraryFrom<&SimulatorEnv> for Update {
fn arbitrary_from<R: Rng>(rng: &mut R, env: &SimulatorEnv) -> Self {
let table = pick(&env.tables, rng);
let mut seen = HashSet::new();
let num_cols = rng.gen_range(1..=table.columns.len());
let set_values: Vec<(String, Value)> = (0..num_cols)
.map(|_| {
let column = loop {
let column = pick(&table.columns, rng);
if seen.contains(&column.name) {
continue;
}
break column;
};
seen.insert(column.name.clone());
(
column.name.clone(),
Value::arbitrary_from(rng, &column.column_type),
)
})
.collect();
Update {
table: table.name.clone(),
set_values,
predicate: Predicate::arbitrary_from(rng, table),
}
}
}

90
simulator/main.rs
View File

@@ -12,9 +12,12 @@ use runner::execution::{execute_plans, Execution, ExecutionHistory, ExecutionRes
use runner::{differential, watch};
use std::any::Any;
use std::backtrace::Backtrace;
use std::fs::OpenOptions;
use std::io::Write;
use std::path::{Path, PathBuf};
use std::sync::{mpsc, Arc, Mutex};
use tracing_subscriber::EnvFilter;
use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt};
mod generation;
mod model;
@@ -192,7 +195,7 @@ fn watch_mode(
match res {
Ok(event) => {
if let EventKind::Modify(ModifyKind::Data(DataChange::Content)) = event.kind {
log::info!("plan file modified, rerunning simulation");
tracing::info!("plan file modified, rerunning simulation");
let result = SandboxedResult::from(
std::panic::catch_unwind(|| {
@@ -211,12 +214,12 @@ fn watch_mode(
);
match result {
SandboxedResult::Correct => {
log::info!("simulation succeeded");
tracing::info!("simulation succeeded");
println!("simulation succeeded");
}
SandboxedResult::Panicked { error, .. }
| SandboxedResult::FoundBug { error, .. } => {
log::error!("simulation failed: '{}'", error);
tracing::error!("simulation failed: '{}'", error);
}
}
}
@@ -238,19 +241,19 @@ fn run_simulator(
last_execution: Arc<Mutex<Execution>>,
) -> Result<(), String> {
std::panic::set_hook(Box::new(move |info| {
log::error!("panic occurred");
tracing::error!("panic occurred");
let payload = info.payload();
if let Some(s) = payload.downcast_ref::<&str>() {
log::error!("{}", s);
tracing::error!("{}", s);
} else if let Some(s) = payload.downcast_ref::<String>() {
log::error!("{}", s);
tracing::error!("{}", s);
} else {
log::error!("unknown panic payload");
tracing::error!("unknown panic payload");
}
let bt = Backtrace::force_capture();
log::error!("captured backtrace:\n{}", bt);
tracing::error!("captured backtrace:\n{}", bt);
}));
let env = Arc::new(Mutex::new(env));
@@ -275,7 +278,7 @@ fn run_simulator(
// No doublecheck, run shrinking if panicking or found a bug.
match &result {
SandboxedResult::Correct => {
log::info!("simulation succeeded");
tracing::info!("simulation succeeded");
println!("simulation succeeded");
bugbase.mark_successful_run(seed, cli_opts).unwrap();
Ok(())
@@ -305,14 +308,14 @@ fn run_simulator(
}
}
log::error!("simulation failed: '{}'", error);
log::info!("Starting to shrink");
tracing::error!("simulation failed: '{}'", error);
tracing::info!("Starting to shrink");
let shrunk_plans = plans
.iter()
.map(|plan| {
let shrunk = plan.shrink_interaction_plan(last_execution);
log::info!("{}", shrunk.stats());
tracing::info!("{}", shrunk.stats());
shrunk
})
.collect::<Vec<_>>();
@@ -346,13 +349,15 @@ fn run_simulator(
SandboxedResult::FoundBug { error: e2, .. },
) => {
if e1 != e2 {
log::error!("shrinking failed, the error was not properly reproduced");
tracing::error!(
"shrinking failed, the error was not properly reproduced"
);
bugbase
.add_bug(seed, plans[0].clone(), Some(error.clone()), cli_opts)
.unwrap();
Err(format!("failed with error: '{}'", error))
} else {
log::info!(
tracing::info!(
"shrinking succeeded, reduced the plan from {} to {}",
plans[0].plan.len(),
shrunk_plans[0].plan.len()
@@ -368,7 +373,7 @@ fn run_simulator(
unreachable!("shrinking should never be called on a correct simulation")
}
_ => {
log::error!("shrinking failed, the error was not properly reproduced");
tracing::error!("shrinking failed, the error was not properly reproduced");
bugbase
.add_bug(seed, plans[0].clone(), Some(error.clone()), cli_opts)
.unwrap();
@@ -438,13 +443,13 @@ fn doublecheck(
match doublecheck_result {
Ok(_) => {
log::info!("doublecheck succeeded");
tracing::info!("doublecheck succeeded");
println!("doublecheck succeeded");
bugbase.mark_successful_run(seed, cli_opts)?;
Ok(())
}
Err(e) => {
log::error!("doublecheck failed: '{}'", e);
tracing::error!("doublecheck failed: '{}'", e);
bugbase
.add_bug(seed, plans[0].clone(), Some(e.clone()), cli_opts)
.unwrap();
@@ -484,13 +489,13 @@ fn differential_testing(
match result {
SandboxedResult::Correct => {
log::info!("simulation succeeded, output of Limbo conforms to SQLite");
tracing::info!("simulation succeeded, output of Limbo conforms to SQLite");
println!("simulation succeeded, output of Limbo conforms to SQLite");
bugbase.mark_successful_run(seed, cli_opts).unwrap();
Ok(())
}
SandboxedResult::Panicked { error, .. } | SandboxedResult::FoundBug { error, .. } => {
log::error!("simulation failed: '{}'", error);
tracing::error!("simulation failed: '{}'", error);
bugbase
.add_bug(seed, plans[0].clone(), Some(error.clone()), cli_opts)
.unwrap();
@@ -529,15 +534,15 @@ impl SandboxedResult {
}
}
Err(payload) => {
log::error!("panic occurred");
tracing::error!("panic occurred");
let err = if let Some(s) = payload.downcast_ref::<&str>() {
log::error!("{}", s);
tracing::error!("{}", s);
s.to_string()
} else if let Some(s) = payload.downcast_ref::<String>() {
log::error!("{}", s);
tracing::error!("{}", s);
s.to_string()
} else {
log::error!("unknown panic payload");
tracing::error!("unknown panic payload");
"unknown panic payload".to_string()
};
@@ -560,6 +565,7 @@ fn setup_simulation(
) -> (u64, SimulatorEnv, Vec<InteractionPlan>) {
if let Some(seed) = &cli_opts.load {
let seed = seed.parse::<u64>().expect("seed should be a number");
tracing::info!("seed={}", seed);
let bug = bugbase
.get_bug(seed)
.unwrap_or_else(|| panic!("bug '{}' not found in bug base", seed));
@@ -595,6 +601,7 @@ fn setup_simulation(
let mut rng = rand::thread_rng();
rng.next_u64()
});
tracing::info!("seed={}", seed);
let paths = bugbase.paths(seed);
if !paths.base.exists() {
@@ -602,7 +609,7 @@ fn setup_simulation(
}
let mut env = SimulatorEnv::new(seed, cli_opts, &paths.db);
log::info!("Generating database interaction plan...");
tracing::info!("Generating database interaction plan...");
let plans = (1..=env.opts.max_connections)
.map(|_| InteractionPlan::arbitrary_from(&mut env.rng.clone(), &mut env))
@@ -610,7 +617,7 @@ fn setup_simulation(
// todo: for now, we only use 1 connection, so it's safe to use the first plan.
let plan = &plans[0];
log::info!("{}", plan.stats());
tracing::info!("{}", plan.stats());
std::fs::write(plan_path(&paths), plan.to_string()).unwrap();
std::fs::write(
plan_path(&paths).with_extension("json"),
@@ -627,7 +634,7 @@ fn run_simulation(
plans: &mut [InteractionPlan],
last_execution: Arc<Mutex<Execution>>,
) -> ExecutionResult {
log::info!("Executing database interaction plan...");
tracing::info!("Executing database interaction plan...");
let mut states = plans
.iter()
@@ -642,17 +649,36 @@ fn run_simulation(
let env = env.lock().unwrap();
env.io.print_stats();
log::info!("Simulation completed");
tracing::info!("Simulation completed");
result
}
fn init_logger() {
env_logger::Builder::from_env(env_logger::Env::default().filter_or("RUST_LOG", "info"))
.format_timestamp(None)
.format_module_path(false)
.format_target(false)
.init();
let file = OpenOptions::new()
.create(true)
.write(true)
.truncate(true)
.open("simulator.log")
.unwrap();
let _ = tracing_subscriber::registry()
.with(
tracing_subscriber::fmt::layer()
.with_ansi(true)
.with_line_number(true)
.without_time()
.with_thread_ids(false),
)
.with(EnvFilter::try_from_default_env().unwrap_or_else(|_| EnvFilter::new("info")))
.with(
tracing_subscriber::fmt::layer()
.with_writer(file)
.with_ansi(false)
.with_line_number(true)
.without_time()
.with_thread_ids(false),
)
.try_init();
}
fn banner() {

7
simulator/model/query/mod.rs
View File

@@ -6,6 +6,7 @@ pub(crate) use drop::Drop;
pub(crate) use insert::Insert;
pub(crate) use select::Select;
use serde::{Deserialize, Serialize};
use update::Update;
use crate::{model::table::Value, runner::env::SimulatorEnv};
@@ -14,6 +15,7 @@ pub mod delete;
pub mod drop;
pub mod insert;
pub mod select;
pub mod update;
// This type represents the potential queries on the database.
#[derive(Debug, Clone, Serialize, Deserialize)]
@@ -22,6 +24,7 @@ pub(crate) enum Query {
Select(Select),
Insert(Insert),
Delete(Delete),
Update(Update),
Drop(Drop),
}
@@ -33,6 +36,7 @@ impl Query {
| Query::Insert(Insert::Select { table, .. })
| Query::Insert(Insert::Values { table, .. })
| Query::Delete(Delete { table, .. })
| Query::Update(Update { table, .. })
| Query::Drop(Drop { table, .. }) => vec![table.clone()],
}
}
@@ -43,6 +47,7 @@ impl Query {
| Query::Insert(Insert::Select { table, .. })
| Query::Insert(Insert::Values { table, .. })
| Query::Delete(Delete { table, .. })
| Query::Update(Update { table, .. })
| Query::Drop(Drop { table, .. }) => vec![table.clone()],
}
}
@@ -53,6 +58,7 @@ impl Query {
Query::Insert(insert) => insert.shadow(env),
Query::Delete(delete) => delete.shadow(env),
Query::Select(select) => select.shadow(env),
Query::Update(update) => update.shadow(env),
Query::Drop(drop) => drop.shadow(env),
}
}
@@ -65,6 +71,7 @@ impl Display for Query {
Self::Select(select) => write!(f, "{}", select),
Self::Insert(insert) => write!(f, "{}", insert),
Self::Delete(delete) => write!(f, "{}", delete),
Self::Update(update) => write!(f, "{}", update),
Self::Drop(drop) => write!(f, "{}", drop),
}
}

56
simulator/model/query/update.rs Normal file
View File

@@ -0,0 +1,56 @@
use std::fmt::Display;
use serde::{Deserialize, Serialize};
use crate::{model::table::Value, SimulatorEnv};
use super::select::Predicate;
#[derive(Clone, Debug, PartialEq, Serialize, Deserialize)]
pub(crate) struct Update {
pub(crate) table: String,
pub(crate) set_values: Vec<(String, Value)>, // Pair of value for set expressions => SET name=value
pub(crate) predicate: Predicate,
}
impl Update {
pub(crate) fn shadow(&self, env: &mut SimulatorEnv) -> Vec<Vec<Value>> {
let table = env
.tables
.iter_mut()
.find(|t| t.name == self.table)
.unwrap();
let t2 = table.clone();
for row in table
.rows
.iter_mut()
.filter(|r| self.predicate.test(r, &t2))
{
for (column, set_value) in &self.set_values {
let (idx, _) = table
.columns
.iter()
.enumerate()
.find(|(_, c)| &c.name == column)
.unwrap();
row[idx] = set_value.clone();
}
}
vec![]
}
}
impl Display for Update {
fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
write!(f, "UPDATE {} SET ", self.table)?;
for (i, (name, value)) in self.set_values.iter().enumerate() {
if i != 0 {
write!(f, ", ")?;
}
write!(f, "{} = {}", name, value)?;
}
write!(f, " WHERE {}", self.predicate)?;
Ok(())
}
}

14
simulator/runner/bugbase.rs
View File

@@ -116,7 +116,7 @@ impl BugBase {
for path in potential_paths {
let path = path.join(".bugbase");
if std::fs::create_dir_all(&path).is_ok() {
log::info!("bug base created at {}", path.display());
tracing::info!("bug base created at {}", path.display());
return BugBase::new(path);
}
}
@@ -172,7 +172,7 @@ impl BugBase {
unreachable!("bug base already exists at {}", path.display());
} else {
std::fs::create_dir_all(&path).or(Err("failed to create bug base"))?;
log::info!("bug base created at {}", path.display());
tracing::info!("bug base created at {}", path.display());
BugBase::new(path)
}
}
@@ -185,7 +185,7 @@ impl BugBase {
error: Option<String>,
cli_options: &SimulatorCLI,
) -> Result<(), String> {
log::debug!("adding bug with seed {}", seed);
tracing::debug!("adding bug with seed {}", seed);
let bug = self.get_bug(seed);
if bug.is_some() {
@@ -290,11 +290,11 @@ impl BugBase {
};
self.bugs.insert(seed, Bug::Loaded(bug.clone()));
log::debug!("Loaded bug with seed {}", seed);
tracing::debug!("Loaded bug with seed {}", seed);
Ok(bug)
}
Some(Bug::Loaded(bug)) => {
log::warn!(
tracing::warn!(
"Bug with seed {} is already loaded, returning the existing plan",
seed
);
@@ -311,7 +311,7 @@ impl BugBase {
let bug = self.get_bug(seed);
match bug {
None => {
log::debug!("removing bug base entry for {}", seed);
tracing::debug!("removing bug base entry for {}", seed);
std::fs::remove_dir_all(self.path.join(seed.to_string()))
.or(Err("should be able to remove bug directory".to_string()))?;
}
@@ -327,7 +327,7 @@ impl BugBase {
// Save the bug to the bug base.
self.save_bug(seed)
.or(Err("should be able to save bug".to_string()))?;
log::debug!("Updated bug with seed {}", seed);
tracing::debug!("Updated bug with seed {}", seed);
}
}

2
simulator/runner/cli.rs
View File

@@ -90,7 +90,7 @@ impl SimulatorCLI {
}
if self.minimum_tests > self.maximum_tests {
log::warn!(
tracing::warn!(
"minimum size '{}' is greater than '{}' maximum size, setting both to '{}'",
self.minimum_tests,
self.maximum_tests,

56
simulator/runner/differential.rs
View File

@@ -22,7 +22,7 @@ pub(crate) fn run_simulation(
plans: &mut [InteractionPlan],
last_execution: Arc<Mutex<Execution>>,
) -> ExecutionResult {
log::info!("Executing database interaction plan...");
tracing::info!("Executing database interaction plan...");
let mut states = plans
.iter()
@@ -52,7 +52,7 @@ pub(crate) fn run_simulation(
last_execution,
);
log::info!("Simulation completed");
tracing::info!("Simulation completed");
result
}
@@ -101,6 +101,10 @@ fn execute_query_rusqlite(
connection.execute(drop.to_string().as_str(), ())?;
Ok(vec![])
}
Query::Update(update) => {
connection.execute(update.to_string().as_str(), ())?;
Ok(vec![])
}
}
}
@@ -184,7 +188,7 @@ fn execute_plan(
match (connection, rusqlite_connection) {
(SimConnection::Disconnected, SimConnection::Disconnected) => {
log::debug!("connecting {}", connection_index);
tracing::debug!("connecting {}", connection_index);
env.connections[connection_index] =
SimConnection::LimboConnection(env.db.connect().unwrap());
rusqlite_env.connections[connection_index] =
@@ -202,7 +206,7 @@ fn execute_plan(
match (limbo_result, ruqlite_result) {
(Ok(next_execution), Ok(next_execution_rusqlite)) => {
if next_execution != next_execution_rusqlite {
log::error!("limbo and rusqlite results do not match");
tracing::error!("limbo and rusqlite results do not match");
return Err(limbo_core::LimboError::InternalError(
"limbo and rusqlite results do not match".into(),
));
@@ -215,30 +219,30 @@ fn execute_plan(
match (limbo_values, rusqlite_values) {
(Ok(limbo_values), Ok(rusqlite_values)) => {
if limbo_values != rusqlite_values {
log::error!("limbo and rusqlite results do not match");
tracing::error!("limbo and rusqlite results do not match");
return Err(limbo_core::LimboError::InternalError(
"limbo and rusqlite results do not match".into(),
));
}
}
(Err(limbo_err), Err(rusqlite_err)) => {
log::warn!(
tracing::warn!(
"limbo and rusqlite both fail, requires manual check"
);
log::warn!("limbo error {}", limbo_err);
log::warn!("rusqlite error {}", rusqlite_err);
tracing::warn!("limbo error {}", limbo_err);
tracing::warn!("rusqlite error {}", rusqlite_err);
}
(Ok(limbo_result), Err(rusqlite_err)) => {
log::error!("limbo and rusqlite results do not match");
log::error!("limbo values {:?}", limbo_result);
log::error!("rusqlite error {}", rusqlite_err);
tracing::error!("limbo and rusqlite results do not match");
tracing::error!("limbo values {:?}", limbo_result);
tracing::error!("rusqlite error {}", rusqlite_err);
return Err(limbo_core::LimboError::InternalError(
"limbo and rusqlite results do not match".into(),
));
}
(Err(limbo_err), Ok(_)) => {
log::error!("limbo and rusqlite results do not match");
log::error!("limbo error {}", limbo_err);
tracing::error!("limbo and rusqlite results do not match");
tracing::error!("limbo error {}", limbo_err);
return Err(limbo_core::LimboError::InternalError(
"limbo and rusqlite results do not match".into(),
));
@@ -247,7 +251,7 @@ fn execute_plan(
}
(None, None) => {}
_ => {
log::error!("limbo and rusqlite results do not match");
tracing::error!("limbo and rusqlite results do not match");
return Err(limbo_core::LimboError::InternalError(
"limbo and rusqlite results do not match".into(),
));
@@ -276,20 +280,20 @@ fn execute_plan(
}
}
(Err(err), Ok(_)) => {
log::error!("limbo and rusqlite results do not match");
log::error!("limbo error {}", err);
tracing::error!("limbo and rusqlite results do not match");
tracing::error!("limbo error {}", err);
return Err(err);
}
(Ok(val), Err(err)) => {
log::error!("limbo and rusqlite results do not match");
log::error!("limbo {:?}", val);
log::error!("rusqlite error {}", err);
tracing::error!("limbo and rusqlite results do not match");
tracing::error!("limbo {:?}", val);
tracing::error!("rusqlite error {}", err);
return Err(err);
}
(Err(err), Err(err_rusqlite)) => {
log::error!("limbo and rusqlite both fail, requires manual check");
log::error!("limbo error {}", err);
log::error!("rusqlite error {}", err_rusqlite);
tracing::error!("limbo and rusqlite both fail, requires manual check");
tracing::error!("limbo error {}", err);
tracing::error!("rusqlite error {}", err_rusqlite);
return Err(err);
}
}
@@ -306,7 +310,7 @@ fn execute_interaction_rusqlite(
interaction: &Interaction,
stack: &mut Vec<ResultSet>,
) -> limbo_core::Result<ExecutionContinuation> {
log::trace!(
tracing::trace!(
"execute_interaction_rusqlite(connection_index={}, interaction={})",
connection_index,
interaction
@@ -319,11 +323,11 @@ fn execute_interaction_rusqlite(
SimConnection::Disconnected => unreachable!(),
};
log::debug!("{}", interaction);
tracing::debug!("{}", interaction);
let results = execute_query_rusqlite(conn, query).map_err(|e| {
limbo_core::LimboError::InternalError(format!("error executing query: {}", e))
});
log::debug!("{:?}", results);
tracing::debug!("{:?}", results);
stack.push(results);
}
Interaction::Assertion(_) => {
@@ -335,7 +339,7 @@ fn execute_interaction_rusqlite(
stack.clear();
if assumption_result.is_err() {
log::warn!("assumption failed: {:?}", assumption_result);
tracing::warn!("assumption failed: {:?}", assumption_result);
return Ok(ExecutionContinuation::NextProperty);
}
}

18
simulator/runner/execution.rs
View File

@@ -121,15 +121,15 @@ fn execute_plan(
let interaction = &plan.plan[state.interaction_pointer].interactions()[state.secondary_pointer];
if let SimConnection::Disconnected = connection {
log::debug!("connecting {}", connection_index);
tracing::debug!("connecting {}", connection_index);
env.connections[connection_index] =
SimConnection::LimboConnection(env.db.connect().unwrap());
} else {
log::debug!("connection {} already connected", connection_index);
tracing::debug!("connection {} already connected", connection_index);
match execute_interaction(env, connection_index, interaction, &mut state.stack) {
Ok(next_execution) => {
interaction.shadow(env);
log::debug!("connection {} processed", connection_index);
tracing::debug!("connection {} processed", connection_index);
// Move to the next interaction or property
match next_execution {
ExecutionContinuation::NextInteraction => {
@@ -152,7 +152,7 @@ fn execute_plan(
}
}
Err(err) => {
log::error!("error {}", err);
tracing::error!("error {}", err);
return Err(err);
}
}
@@ -179,7 +179,7 @@ pub(crate) fn execute_interaction(
interaction: &Interaction,
stack: &mut Vec<ResultSet>,
) -> Result<ExecutionContinuation> {
log::trace!(
tracing::trace!(
"execute_interaction(connection_index={}, interaction={})",
connection_index,
interaction
@@ -192,9 +192,9 @@ pub(crate) fn execute_interaction(
SimConnection::Disconnected => unreachable!(),
};
log::debug!("{}", interaction);
let results = interaction.execute_query(conn);
log::debug!("{:?}", results);
tracing::debug!("{}", interaction);
let results = interaction.execute_query(conn, &env.io);
tracing::debug!("{:?}", results);
stack.push(results);
}
Interaction::Assertion(_) => {
@@ -206,7 +206,7 @@ pub(crate) fn execute_interaction(
stack.clear();
if assumption_result.is_err() {
log::warn!("assumption failed: {:?}", assumption_result);
tracing::warn!("assumption failed: {:?}", assumption_result);
return Ok(ExecutionContinuation::NextProperty);
}
}

14
simulator/runner/file.rs
View File

@@ -32,29 +32,29 @@ impl SimulatorFile {
}
pub(crate) fn print_stats(&self) {
log::info!("op calls faults");
log::info!("--------- -------- --------");
log::info!(
tracing::info!("op calls faults");
tracing::info!("--------- -------- --------");
tracing::info!(
"pread {:8} {:8}",
*self.nr_pread_calls.borrow(),
*self.nr_pread_faults.borrow()
);
log::info!(
tracing::info!(
"pwrite {:8} {:8}",
*self.nr_pwrite_calls.borrow(),
*self.nr_pwrite_faults.borrow()
);
log::info!(
tracing::info!(
"sync {:8} {:8}",
*self.nr_sync_calls.borrow(),
0 // No fault counter for sync
);
log::info!("--------- -------- --------");
tracing::info!("--------- -------- --------");
let sum_calls = *self.nr_pread_calls.borrow()
+ *self.nr_pwrite_calls.borrow()
+ *self.nr_sync_calls.borrow();
let sum_faults = *self.nr_pread_faults.borrow() + *self.nr_pwrite_faults.borrow();
log::info!("total {:8} {:8}", sum_calls, sum_faults);
tracing::info!("total {:8} {:8}", sum_calls, sum_faults);
}
}

6
simulator/runner/io.rs
View File

@@ -43,10 +43,10 @@ impl SimulatorIO {
}
pub(crate) fn print_stats(&self) {
log::info!("run_once faults: {}", self.nr_run_once_faults.borrow());
tracing::info!("run_once faults: {}", self.nr_run_once_faults.borrow());
for file in self.files.borrow().iter() {
log::info!("");
log::info!("===========================");
tracing::info!("");
tracing::info!("===========================");
file.print_stats();
}
}

8
simulator/runner/watch.rs
View File

@@ -31,7 +31,7 @@ pub(crate) fn run_simulation(
let env = env.lock().unwrap();
env.io.print_stats();
log::info!("Simulation completed");
tracing::info!("Simulation completed");
result
}
@@ -97,13 +97,13 @@ fn execute_plan(
let interaction = &plan[state.interaction_pointer][state.secondary_pointer];
if let SimConnection::Disconnected = connection {
log::debug!("connecting {}", connection_index);
tracing::debug!("connecting {}", connection_index);
env.connections[connection_index] =
SimConnection::LimboConnection(env.db.connect().unwrap());
} else {
match execute_interaction(env, connection_index, interaction, &mut state.stack) {
Ok(next_execution) => {
log::debug!("connection {} processed", connection_index);
tracing::debug!("connection {} processed", connection_index);
// Move to the next interaction or property
match next_execution {
ExecutionContinuation::NextInteraction => {
@@ -124,7 +124,7 @@ fn execute_plan(
}
}
Err(err) => {
log::error!("error {}", err);
tracing::error!("error {}", err);
return Err(err);
}
}

2
simulator/shrink/plan.rs
View File

@@ -46,7 +46,7 @@ impl InteractionPlan {
let after = plan.plan.len();
log::info!(
tracing::info!(
"Shrinking interaction plan from {} to {} properties",
before,
after