From bc563266b3027b1af2c93a250de4df553a662d4f Mon Sep 17 00:00:00 2001 From: pedrocarlo Date: Fri, 30 May 2025 20:35:50 -0300 Subject: [PATCH 1/3] add instrumentation to more functions for debugging + adjust how cursors are opened --- core/lib.rs | 5 ++++ core/translate/emitter.rs | 59 +++++++++++++++++++++++++++++++-------- core/translate/mod.rs | 2 ++ core/vdbe/builder.rs | 4 +++ 4 files changed, 59 insertions(+), 11 deletions(-) diff --git a/core/lib.rs b/core/lib.rs index a2d5d52e9..592992532 100644 --- a/core/lib.rs +++ b/core/lib.rs @@ -76,6 +76,7 @@ use storage::{ pager::allocate_page, sqlite3_ondisk::{DatabaseHeader, DATABASE_HEADER_SIZE}, }; +use tracing::{instrument, Level}; use translate::select::prepare_select_plan; pub use types::RefValue; pub use types::Value; @@ -339,6 +340,7 @@ pub struct Connection { } impl Connection { + #[instrument(skip_all, level = Level::TRACE)] pub fn prepare(self: &Rc, sql: impl AsRef) -> Result { if sql.as_ref().is_empty() { return Err(LimboError::InvalidArgument( @@ -377,6 +379,7 @@ impl Connection { } } + #[instrument(skip_all, level = Level::TRACE)] pub fn query(self: &Rc, sql: impl AsRef) -> Result> { let sql = sql.as_ref(); tracing::trace!("Querying: {}", sql); @@ -388,6 +391,7 @@ impl Connection { } } + #[instrument(skip_all, level = Level::TRACE)] pub(crate) fn run_cmd(self: &Rc, cmd: Cmd) -> Result> { let syms = self.syms.borrow(); match cmd { @@ -448,6 +452,7 @@ impl Connection { /// Execute will run a query from start to finish taking ownership of I/O because it will run pending I/Os if it didn't finish. /// TODO: make this api async + #[instrument(skip_all, level = Level::TRACE)] pub fn execute(self: &Rc, sql: impl AsRef) -> Result<()> { let sql = sql.as_ref(); let mut parser = Parser::new(sql.as_bytes()); diff --git a/core/translate/emitter.rs b/core/translate/emitter.rs index 5ac86303c..b20951cc1 100644 --- a/core/translate/emitter.rs +++ b/core/translate/emitter.rs @@ -1,10 +1,12 @@ // This module contains code for emitting bytecode instructions for SQL query execution. // It handles translating high-level SQL operations into low-level bytecode that can be executed by the virtual machine. +use std::collections::HashMap; use std::rc::Rc; use std::sync::Arc; use limbo_sqlite3_parser::ast::{self, SortOrder}; +use tracing::{instrument, Level}; use super::aggregation::emit_ungrouped_aggregation; use super::expr::{translate_condition_expr, translate_expr, ConditionMetadata}; @@ -175,6 +177,7 @@ pub enum TransactionMode { /// Main entry point for emitting bytecode for a SQL query /// Takes a query plan and generates the corresponding bytecode program +#[instrument(skip_all, level = Level::TRACE)] pub fn emit_program( program: &mut ProgramBuilder, plan: Plan, @@ -191,6 +194,7 @@ pub fn emit_program( } } +#[instrument(skip_all, level = Level::TRACE)] fn emit_program_for_compound_select( program: &mut ProgramBuilder, plan: Plan, @@ -465,6 +469,7 @@ fn read_deduplicated_union_rows( }); } +#[instrument(skip_all, level = Level::TRACE)] fn emit_program_for_select( program: &mut ProgramBuilder, mut plan: SelectPlan, @@ -503,6 +508,7 @@ fn emit_program_for_select( Ok(()) } +#[instrument(skip_all, level = Level::TRACE)] pub fn emit_query<'a>( program: &'a mut ProgramBuilder, plan: &'a mut SelectPlan, @@ -641,6 +647,7 @@ pub fn emit_query<'a>( Ok(t_ctx.reg_result_cols_start.unwrap()) } +#[instrument(skip_all, level = Level::TRACE)] fn emit_program_for_delete( program: &mut ProgramBuilder, mut plan: DeletePlan, @@ -684,6 +691,33 @@ fn emit_program_for_delete( OperationMode::DELETE, )?; + // Open indexes for delete. + // Order is important. This segment of code must be run before `open_loop` + let mut index_cursors = HashMap::with_capacity(plan.indexes.len()); + + for table_ref in plan.table_references.joined_tables() { + let index_cursor_id = table_ref.op.index().map(|index| { + program.resolve_cursor_id(&CursorKey::index(table_ref.internal_id, index.clone())) + }); + if let Some(index_cursor) = index_cursor_id { + let index = table_ref.op.index().unwrap(); + index_cursors.insert(index.name.as_str(), index_cursor); + } + } + for index in &plan.indexes { + index_cursors.entry(index.name.as_str()).or_insert_with(|| { + let index_cursor_id = program.alloc_cursor_id(CursorType::BTreeIndex(index.clone())); + program.emit_insn(Insn::OpenWrite { + cursor_id: index_cursor_id, + root_page: RegisterOrLiteral::Literal(index.root_page), + name: index.name.clone(), + }); + index_cursor_id + }); + } + + assert_eq!(index_cursors.len(), plan.indexes.len()); + // Set up main query execution loop open_loop( program, @@ -692,7 +726,14 @@ fn emit_program_for_delete( &[JoinOrderMember::default()], &mut plan.where_clause, )?; - emit_delete_insns(program, &mut t_ctx, &plan.table_references, &plan.indexes)?; + + emit_delete_insns( + program, + &mut t_ctx, + &plan.table_references, + &plan.indexes, + index_cursors.values().into_iter(), + )?; // Clean up and close the main execution loop close_loop( @@ -710,11 +751,12 @@ fn emit_program_for_delete( Ok(()) } -fn emit_delete_insns( +fn emit_delete_insns<'a, T: Iterator>( program: &mut ProgramBuilder, t_ctx: &mut TranslateCtx, table_references: &TableReferences, index_references: &[Arc], + index_cursors: T, ) -> Result<()> { let table_reference = table_references.joined_tables().first().unwrap(); let cursor_id = match &table_reference.op { @@ -759,14 +801,7 @@ fn emit_delete_insns( conflict_action, }); } else { - for index in index_references { - let index_cursor_id = program.alloc_cursor_id(CursorType::BTreeIndex(index.clone())); - - program.emit_insn(Insn::OpenWrite { - cursor_id: index_cursor_id, - root_page: RegisterOrLiteral::Literal(index.root_page), - name: index.name.clone(), - }); + for (index, index_cursor_id) in index_references.iter().zip(index_cursors) { let num_regs = index.columns.len() + 1; let start_reg = program.alloc_registers(num_regs); // Emit columns that are part of the index @@ -788,7 +823,7 @@ fn emit_delete_insns( program.emit_insn(Insn::IdxDelete { start_reg, num_regs, - cursor_id: index_cursor_id, + cursor_id: *index_cursor_id, }); } program.emit_insn(Insn::Delete { @@ -805,6 +840,7 @@ fn emit_delete_insns( Ok(()) } +#[instrument(skip_all, level = Level::TRACE)] fn emit_program_for_update( program: &mut ProgramBuilder, mut plan: UpdatePlan, @@ -893,6 +929,7 @@ fn emit_program_for_update( Ok(()) } +#[instrument(skip_all, level = Level::TRACE)] fn emit_update_insns( plan: &UpdatePlan, t_ctx: &TranslateCtx, diff --git a/core/translate/mod.rs b/core/translate/mod.rs index 390b1d833..04b4e52e8 100644 --- a/core/translate/mod.rs +++ b/core/translate/mod.rs @@ -49,9 +49,11 @@ use schema::{ use select::translate_select; use std::rc::{Rc, Weak}; use std::sync::Arc; +use tracing::{instrument, Level}; use transaction::{translate_tx_begin, translate_tx_commit}; use update::translate_update; +#[instrument(skip_all, level = Level::TRACE)] pub fn translate( schema: &Schema, stmt: ast::Stmt, diff --git a/core/vdbe/builder.rs b/core/vdbe/builder.rs index 7d2773fc6..c2f9bfd1f 100644 --- a/core/vdbe/builder.rs +++ b/core/vdbe/builder.rs @@ -6,6 +6,7 @@ use std::{ }; use limbo_sqlite3_parser::ast::{self, TableInternalId}; +use tracing::{instrument, Level}; use crate::{ fast_lock::SpinLock, @@ -284,8 +285,11 @@ impl ProgramBuilder { cursor } + #[instrument(skip(self), level = Level::TRACE)] pub fn emit_insn(&mut self, insn: Insn) { let function = insn.to_function(); + // This seemingly empty trace here is needed so that a function span is emmited with it + tracing::trace!(""); self.insns.push((insn, function, self.insns.len())); } From c9c73f249777384392ca1740dcab0427205f0b23 Mon Sep 17 00:00:00 2001 From: pedrocarlo Date: Sat, 31 May 2025 01:19:26 -0300 Subject: [PATCH 2/3] fix explain panicking on None CursorKey --- core/vdbe/explain.rs | 58 +++++++++++++++++++++++++++----------------- 1 file changed, 36 insertions(+), 22 deletions(-) diff --git a/core/vdbe/explain.rs b/core/vdbe/explain.rs index 35bdac8f7..69bb886c1 100644 --- a/core/vdbe/explain.rs +++ b/core/vdbe/explain.rs @@ -365,14 +365,20 @@ pub fn insn_to_str( Value::build_text(""), 0, { - let cursor_key = program.cursor_ref[*cursor_id].0.as_ref().unwrap(); + let cursor_type = + program.cursor_ref[*cursor_id] + .0 + .as_ref() + .map_or("", |cursor_key| { + if cursor_key.index.is_some() { + "index" + } else { + "table" + } + }); format!( "{}={}, root={}", - if cursor_key.index.is_some() { - "index" - } else { - "table" - }, + cursor_type, get_table_or_index_name(*cursor_id), root_page ) @@ -386,16 +392,18 @@ pub fn insn_to_str( Value::build_text(""), 0, { - let cursor_key = program.cursor_ref[*cursor_id].0.as_ref().unwrap(); - format!( - "{} {}", - if cursor_key.index.is_some() { - "index" - } else { - "table" - }, - get_table_or_index_name(*cursor_id), - ) + let cursor_type = + program.cursor_ref[*cursor_id] + .0 + .as_ref() + .map_or("", |cursor_key| { + if cursor_key.index.is_some() { + "index" + } else { + "table" + } + }); + format!("{} {}", cursor_type, get_table_or_index_name(*cursor_id),) }, ), Insn::VCreate { @@ -497,14 +505,20 @@ pub fn insn_to_str( Value::build_text(""), 0, { - let cursor_key = program.cursor_ref[*cursor_id].0.as_ref().unwrap(); + let cursor_type = + program.cursor_ref[*cursor_id] + .0 + .as_ref() + .map_or("", |cursor_key| { + if cursor_key.index.is_some() { + "index" + } else { + "table" + } + }); format!( "Rewind {} {}", - if cursor_key.index.is_some() { - "index" - } else { - "table" - }, + cursor_type, get_table_or_index_name(*cursor_id), ) }, From 9dc6638313d7626fc14865782ad4d025f75441bc Mon Sep 17 00:00:00 2001 From: pedrocarlo Date: Sun, 1 Jun 2025 21:42:54 -0300 Subject: [PATCH 3/3] cleaner approach for opening indexes --- core/translate/emitter.rs | 57 +++++++++++++++++++-------------------- 1 file changed, 28 insertions(+), 29 deletions(-) diff --git a/core/translate/emitter.rs b/core/translate/emitter.rs index b20951cc1..dc73bdc87 100644 --- a/core/translate/emitter.rs +++ b/core/translate/emitter.rs @@ -1,7 +1,6 @@ // This module contains code for emitting bytecode instructions for SQL query execution. // It handles translating high-level SQL operations into low-level bytecode that can be executed by the virtual machine. -use std::collections::HashMap; use std::rc::Rc; use std::sync::Arc; @@ -693,30 +692,32 @@ fn emit_program_for_delete( // Open indexes for delete. // Order is important. This segment of code must be run before `open_loop` - let mut index_cursors = HashMap::with_capacity(plan.indexes.len()); - for table_ref in plan.table_references.joined_tables() { - let index_cursor_id = table_ref.op.index().map(|index| { - program.resolve_cursor_id(&CursorKey::index(table_ref.internal_id, index.clone())) - }); - if let Some(index_cursor) = index_cursor_id { - let index = table_ref.op.index().unwrap(); - index_cursors.insert(index.name.as_str(), index_cursor); - } - } - for index in &plan.indexes { - index_cursors.entry(index.name.as_str()).or_insert_with(|| { - let index_cursor_id = program.alloc_cursor_id(CursorType::BTreeIndex(index.clone())); - program.emit_insn(Insn::OpenWrite { - cursor_id: index_cursor_id, - root_page: RegisterOrLiteral::Literal(index.root_page), - name: index.name.clone(), - }); - index_cursor_id - }); - } + let table_ref = plan.table_references.joined_tables().first().unwrap(); + let index_references = plan + .indexes + .iter() + .map(|index| { + if table_ref + .op + .index() + .is_some_and(|table_ref_index| table_ref_index.name == index.name) + { + ( + index.clone(), + program + .resolve_cursor_id(&CursorKey::index(table_ref.internal_id, index.clone())), + ) + } else { + ( + index.clone(), + program.alloc_cursor_id(CursorType::BTreeIndex(index.clone())), + ) + } + }) + .collect::>(); - assert_eq!(index_cursors.len(), plan.indexes.len()); + assert_eq!(index_references.len(), plan.indexes.len()); // Set up main query execution loop open_loop( @@ -731,8 +732,7 @@ fn emit_program_for_delete( program, &mut t_ctx, &plan.table_references, - &plan.indexes, - index_cursors.values().into_iter(), + &index_references, )?; // Clean up and close the main execution loop @@ -751,12 +751,11 @@ fn emit_program_for_delete( Ok(()) } -fn emit_delete_insns<'a, T: Iterator>( +fn emit_delete_insns( program: &mut ProgramBuilder, t_ctx: &mut TranslateCtx, table_references: &TableReferences, - index_references: &[Arc], - index_cursors: T, + index_references: &[(Arc, usize)], ) -> Result<()> { let table_reference = table_references.joined_tables().first().unwrap(); let cursor_id = match &table_reference.op { @@ -801,7 +800,7 @@ fn emit_delete_insns<'a, T: Iterator>( conflict_action, }); } else { - for (index, index_cursor_id) in index_references.iter().zip(index_cursors) { + for (index, index_cursor_id) in index_references { let num_regs = index.columns.len() + 1; let start_reg = program.alloc_registers(num_regs); // Emit columns that are part of the index