From b85687658d2c43d3540dc9a41e249e79ba37a9f7 Mon Sep 17 00:00:00 2001 From: pedrocarlo Date: Sat, 5 Jul 2025 17:24:51 -0300 Subject: [PATCH] change instrumentation level to INFO --- core/io/unix.rs | 10 ++-- core/lib.rs | 8 ++-- core/storage/btree.rs | 78 +++++++++++++++---------------- core/storage/database.rs | 16 +++---- core/storage/pager.rs | 32 ++++++------- core/storage/sqlite3_ondisk.rs | 8 ++-- core/storage/wal.rs | 26 +++++------ core/translate/compound_select.rs | 2 +- core/translate/emitter.rs | 12 ++--- core/translate/expr.rs | 4 +- core/translate/mod.rs | 2 +- core/vdbe/builder.rs | 2 +- core/vdbe/mod.rs | 8 ++-- simulator/generation/property.rs | 1 - 14 files changed, 104 insertions(+), 105 deletions(-) diff --git a/core/io/unix.rs b/core/io/unix.rs index b4078579d..235df10d0 100644 --- a/core/io/unix.rs +++ b/core/io/unix.rs @@ -219,7 +219,7 @@ impl IO for UnixIO { Ok(unix_file) } - #[instrument(err, skip_all, level = Level::TRACE)] + #[instrument(err, skip_all, level = Level::INFO)] fn run_once(&self) -> Result<()> { if self.callbacks.is_empty() { return Ok(()); @@ -334,7 +334,7 @@ impl File for UnixFile<'_> { Ok(()) } - #[instrument(err, skip_all, level = Level::TRACE)] + #[instrument(err, skip_all, level = Level::INFO)] fn pread(&self, pos: usize, c: Completion) -> Result> { let file = self.file.borrow(); let result = { @@ -368,7 +368,7 @@ impl File for UnixFile<'_> { } } - #[instrument(err, skip_all, level = Level::TRACE)] + #[instrument(err, skip_all, level = Level::INFO)] fn pwrite( &self, pos: usize, @@ -404,7 +404,7 @@ impl File for UnixFile<'_> { } } - #[instrument(err, skip_all, level = Level::TRACE)] + #[instrument(err, skip_all, level = Level::INFO)] fn sync(&self, c: Completion) -> Result> { let file = self.file.borrow(); let result = fs::fsync(file.as_fd()); @@ -419,7 +419,7 @@ impl File for UnixFile<'_> { } } - #[instrument(err, skip_all, level = Level::TRACE)] + #[instrument(err, skip_all, level = Level::INFO)] fn size(&self) -> Result { let file = self.file.borrow(); Ok(file.metadata()?.len()) diff --git a/core/lib.rs b/core/lib.rs index cfa140e7a..000fb9667 100644 --- a/core/lib.rs +++ b/core/lib.rs @@ -464,7 +464,7 @@ pub struct Connection { } impl Connection { - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn prepare(self: &Arc, sql: impl AsRef) -> Result { if sql.as_ref().is_empty() { return Err(LimboError::InvalidArgument( @@ -505,7 +505,7 @@ impl Connection { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn query(self: &Arc, sql: impl AsRef) -> Result> { let sql = sql.as_ref(); tracing::trace!("Querying: {}", sql); @@ -521,7 +521,7 @@ impl Connection { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub(crate) fn run_cmd( self: &Arc, cmd: Cmd, @@ -574,7 +574,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)] + #[instrument(skip_all, level = Level::INFO)] pub fn execute(self: &Arc, sql: impl AsRef) -> Result<()> { let sql = sql.as_ref(); let mut parser = Parser::new(sql.as_bytes()); diff --git a/core/storage/btree.rs b/core/storage/btree.rs index ace2d72f2..c7ab3ea4a 100644 --- a/core/storage/btree.rs +++ b/core/storage/btree.rs @@ -592,7 +592,7 @@ impl BTreeCursor { /// Check if the table is empty. /// This is done by checking if the root page has no cells. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn is_empty_table(&self) -> Result> { if let Some(mv_cursor) = &self.mv_cursor { let mv_cursor = mv_cursor.borrow(); @@ -607,7 +607,7 @@ impl BTreeCursor { /// Move the cursor to the previous record and return it. /// Used in backwards iteration. - #[instrument(skip(self), level = Level::TRACE, name = "prev")] + #[instrument(skip(self), level = Level::INFO, name = "prev")] fn get_prev_record(&mut self) -> Result> { loop { let page = self.stack.top(); @@ -718,7 +718,7 @@ impl BTreeCursor { /// Reads the record of a cell that has overflow pages. This is a state machine that requires to be called until completion so everything /// that calls this function should be reentrant. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn process_overflow_read( &self, payload: &'static [u8], @@ -836,7 +836,7 @@ impl BTreeCursor { /// /// If the cell has overflow pages, it will skip till the overflow page which /// is at the offset given. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn read_write_payload_with_offset( &mut self, mut offset: u32, @@ -947,7 +947,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(())) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn continue_payload_overflow_with_offset( &mut self, buffer: &mut Vec, @@ -1124,7 +1124,7 @@ impl BTreeCursor { /// Move the cursor to the next record and return it. /// Used in forwards iteration, which is the default. - #[instrument(skip(self), level = Level::TRACE, name = "next")] + #[instrument(skip(self), level = Level::INFO, name = "next")] fn get_next_record(&mut self) -> Result> { if let Some(mv_cursor) = &self.mv_cursor { let mut mv_cursor = mv_cursor.borrow_mut(); @@ -1264,7 +1264,7 @@ impl BTreeCursor { } /// Move the cursor to the root page of the btree. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn move_to_root(&mut self) -> Result<()> { self.seek_state = CursorSeekState::Start; self.going_upwards = false; @@ -1276,7 +1276,7 @@ impl BTreeCursor { } /// Move the cursor to the rightmost record in the btree. - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] fn move_to_rightmost(&mut self) -> Result> { self.move_to_root()?; @@ -1311,7 +1311,7 @@ impl BTreeCursor { } /// Specialized version of move_to() for table btrees. - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] fn tablebtree_move_to(&mut self, rowid: i64, seek_op: SeekOp) -> Result> { 'outer: loop { let page = self.stack.top(); @@ -1429,7 +1429,7 @@ impl BTreeCursor { } /// Specialized version of move_to() for index btrees. - #[instrument(skip(self, index_key), level = Level::TRACE)] + #[instrument(skip(self, index_key), level = Level::INFO)] fn indexbtree_move_to( &mut self, index_key: &ImmutableRecord, @@ -1645,7 +1645,7 @@ impl BTreeCursor { /// Specialized version of do_seek() for table btrees that uses binary search instead /// of iterating cells in order. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn tablebtree_seek(&mut self, rowid: i64, seek_op: SeekOp) -> Result> { turso_assert!( self.mv_cursor.is_none(), @@ -1765,7 +1765,7 @@ impl BTreeCursor { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn indexbtree_seek( &mut self, key: &ImmutableRecord, @@ -2036,7 +2036,7 @@ impl BTreeCursor { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn move_to(&mut self, key: SeekKey<'_>, cmp: SeekOp) -> Result> { turso_assert!( self.mv_cursor.is_none(), @@ -2089,7 +2089,7 @@ impl BTreeCursor { /// Insert a record into the btree. /// If the insert operation overflows the page, it will be split and the btree will be balanced. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn insert_into_page(&mut self, bkey: &BTreeKey) -> Result> { let record = bkey .get_record() @@ -2270,7 +2270,7 @@ impl BTreeCursor { /// This is a naive algorithm that doesn't try to distribute cells evenly by content. /// It will try to split the page in half by keys not by content. /// Sqlite tries to have a page at least 40% full. - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] fn balance(&mut self) -> Result> { turso_assert!( matches!(self.state, CursorState::Write(_)), @@ -2332,7 +2332,7 @@ impl BTreeCursor { } /// Balance a non root page by trying to balance cells between a maximum of 3 siblings that should be neighboring the page that overflowed/underflowed. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn balance_non_root(&mut self) -> Result> { turso_assert!( matches!(self.state, CursorState::Write(_)), @@ -3868,7 +3868,7 @@ impl BTreeCursor { } /// Find the index of the cell in the page that contains the given rowid. - #[instrument( skip_all, level = Level::TRACE)] + #[instrument( skip_all, level = Level::INFO)] fn find_cell(&mut self, page: &PageContent, key: &BTreeKey) -> Result> { if self.find_cell_state.0.is_none() { self.find_cell_state.set(0); @@ -3943,7 +3943,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(cell_idx)) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn seek_end(&mut self) -> Result> { assert!(self.mv_cursor.is_none()); // unsure about this -_- self.move_to_root()?; @@ -3972,7 +3972,7 @@ impl BTreeCursor { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn seek_to_last(&mut self) -> Result> { let has_record = return_if_io!(self.move_to_rightmost()); self.invalidate_record(); @@ -3993,7 +3993,7 @@ impl BTreeCursor { self.root_page } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn rewind(&mut self) -> Result> { if self.mv_cursor.is_some() { let cursor_has_record = return_if_io!(self.get_next_record()); @@ -4009,7 +4009,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(())) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn last(&mut self) -> Result> { assert!(self.mv_cursor.is_none()); let cursor_has_record = return_if_io!(self.move_to_rightmost()); @@ -4018,7 +4018,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(())) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn next(&mut self) -> Result> { return_if_io!(self.restore_context()); let cursor_has_record = return_if_io!(self.get_next_record()); @@ -4034,7 +4034,7 @@ impl BTreeCursor { .invalidate(); } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn prev(&mut self) -> Result> { assert!(self.mv_cursor.is_none()); return_if_io!(self.restore_context()); @@ -4044,7 +4044,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(cursor_has_record)) } - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn rowid(&mut self) -> Result>> { if let Some(mv_cursor) = &self.mv_cursor { let mv_cursor = mv_cursor.borrow(); @@ -4086,7 +4086,7 @@ impl BTreeCursor { } } - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn seek(&mut self, key: SeekKey<'_>, op: SeekOp) -> Result> { assert!(self.mv_cursor.is_none()); // Empty trace to capture the span information @@ -4107,7 +4107,7 @@ impl BTreeCursor { /// Return a reference to the record the cursor is currently pointing to. /// If record was not parsed yet, then we have to parse it and in case of I/O we yield control /// back. - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn record(&self) -> Result>>> { if !self.has_record.get() { return Ok(CursorResult::Ok(None)); @@ -4175,7 +4175,7 @@ impl BTreeCursor { Ok(CursorResult::Ok(Some(record_ref))) } - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn insert( &mut self, key: &BTreeKey, @@ -4245,7 +4245,7 @@ impl BTreeCursor { /// 7. WaitForBalancingToComplete -> perform balancing /// 8. SeekAfterBalancing -> adjust the cursor to a node that is closer to the deleted value. go to Finish /// 9. Finish -> Delete operation is done. Return CursorResult(Ok()) - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn delete(&mut self) -> Result> { assert!(self.mv_cursor.is_none()); @@ -4622,7 +4622,7 @@ impl BTreeCursor { } /// Search for a key in an Index Btree. Looking up indexes that need to be unique, we cannot compare the rowid - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn key_exists_in_index(&mut self, key: &ImmutableRecord) -> Result> { return_if_io!(self.seek(SeekKey::IndexKey(key), SeekOp::GE { eq_only: true })); @@ -4652,7 +4652,7 @@ impl BTreeCursor { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn exists(&mut self, key: &Value) -> Result> { assert!(self.mv_cursor.is_none()); let int_key = match key { @@ -4669,7 +4669,7 @@ impl BTreeCursor { /// Clear the overflow pages linked to a specific page provided by the leaf cell /// Uses a state machine to keep track of it's operations so that traversal can be /// resumed from last point after IO interruption - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn clear_overflow_pages(&mut self, cell: &BTreeCell) -> Result> { loop { let state = self.overflow_state.take().unwrap_or(OverflowState::Start); @@ -4738,7 +4738,7 @@ impl BTreeCursor { /// ``` /// /// The destruction order would be: [4',4,5,2,6,7,3,1] - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn btree_destroy(&mut self) -> Result>> { if let CursorState::None = &self.state { self.move_to_root()?; @@ -5014,7 +5014,7 @@ impl BTreeCursor { /// Count the number of entries in the b-tree /// /// Only supposed to be used in the context of a simple Count Select Statement - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] pub fn count(&mut self) -> Result> { if self.count == 0 { self.move_to_root()?; @@ -5123,7 +5123,7 @@ impl BTreeCursor { } /// If context is defined, restore it and set it None on success - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn restore_context(&mut self) -> Result> { if self.context.is_none() || !matches!(self.valid_state, CursorValidState::RequireSeek) { return Ok(CursorResult::Ok(())); @@ -5562,7 +5562,7 @@ impl PageStack { } /// Push a new page onto the stack. /// This effectively means traversing to a child page. - #[instrument(skip_all, level = Level::TRACE, name = "pagestack::push")] + #[instrument(skip_all, level = Level::INFO, name = "pagestack::push")] fn _push(&self, page: BTreePage, starting_cell_idx: i32) { tracing::trace!( current = self.current_page.get(), @@ -5589,7 +5589,7 @@ impl PageStack { /// Pop a page off the stack. /// This effectively means traversing back up to a parent page. - #[instrument(skip_all, level = Level::TRACE, name = "pagestack::pop")] + #[instrument(skip_all, level = Level::INFO, name = "pagestack::pop")] fn pop(&self) { let current = self.current_page.get(); assert!(current >= 0); @@ -5601,7 +5601,7 @@ impl PageStack { /// Get the top page on the stack. /// This is the page that is currently being traversed. - #[instrument(skip(self), level = Level::TRACE, name = "pagestack::top", )] + #[instrument(skip(self), level = Level::INFO, name = "pagestack::top", )] fn top(&self) -> BTreePage { let page = self.stack.borrow()[self.current()] .as_ref() @@ -5633,7 +5633,7 @@ impl PageStack { /// Advance the current cell index of the current page to the next cell. /// We usually advance after going traversing a new page - #[instrument(skip(self), level = Level::TRACE, name = "pagestack::advance",)] + #[instrument(skip(self), level = Level::INFO, name = "pagestack::advance",)] fn advance(&self) { let current = self.current(); tracing::trace!( @@ -5643,7 +5643,7 @@ impl PageStack { self.cell_indices.borrow_mut()[current] += 1; } - #[instrument(skip(self), level = Level::TRACE, name = "pagestack::retreat")] + #[instrument(skip(self), level = Level::INFO, name = "pagestack::retreat")] fn retreat(&self) { let current = self.current(); tracing::trace!( diff --git a/core/storage/database.rs b/core/storage/database.rs index 3744d5025..c2ad2c57a 100644 --- a/core/storage/database.rs +++ b/core/storage/database.rs @@ -33,7 +33,7 @@ unsafe impl Sync for DatabaseFile {} #[cfg(feature = "fs")] impl DatabaseStorage for DatabaseFile { - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn read_page(&self, page_idx: usize, c: Completion) -> Result<()> { let r = c.as_read(); let size = r.buf().len(); @@ -46,7 +46,7 @@ impl DatabaseStorage for DatabaseFile { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn write_page( &self, page_idx: usize, @@ -63,13 +63,13 @@ impl DatabaseStorage for DatabaseFile { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn sync(&self, c: Completion) -> Result<()> { let _ = self.file.sync(c)?; Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn size(&self) -> Result { self.file.size() } @@ -90,7 +90,7 @@ unsafe impl Send for FileMemoryStorage {} unsafe impl Sync for FileMemoryStorage {} impl DatabaseStorage for FileMemoryStorage { - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn read_page(&self, page_idx: usize, c: Completion) -> Result<()> { let r = match c.completion_type { CompletionType::Read(ref r) => r, @@ -106,7 +106,7 @@ impl DatabaseStorage for FileMemoryStorage { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn write_page( &self, page_idx: usize, @@ -122,13 +122,13 @@ impl DatabaseStorage for FileMemoryStorage { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn sync(&self, c: Completion) -> Result<()> { let _ = self.file.sync(c)?; Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn size(&self) -> Result { self.file.size() } diff --git a/core/storage/pager.rs b/core/storage/pager.rs index e5a50e0c1..c67d5581f 100644 --- a/core/storage/pager.rs +++ b/core/storage/pager.rs @@ -471,7 +471,7 @@ impl Pager { /// This method is used to allocate a new root page for a btree, both for tables and indexes /// FIXME: handle no room in page cache - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn btree_create(&self, flags: &CreateBTreeFlags) -> Result> { let page_type = match flags { _ if flags.is_table() => PageType::TableLeaf, @@ -590,7 +590,7 @@ impl Pager { } #[inline(always)] - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn begin_read_tx(&self) -> Result> { // We allocate the first page lazily in the first transaction match self.maybe_allocate_page1()? { @@ -600,7 +600,7 @@ impl Pager { Ok(CursorResult::Ok(self.wal.borrow_mut().begin_read_tx()?)) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn maybe_allocate_page1(&self) -> Result> { if self.is_empty.load(Ordering::SeqCst) < DB_STATE_INITIALIZED { if let Ok(_lock) = self.init_lock.try_lock() { @@ -624,7 +624,7 @@ impl Pager { } #[inline(always)] - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn begin_write_tx(&self) -> Result> { // TODO(Diego): The only possibly allocate page1 here is because OpenEphemeral needs a write transaction // we should have a unique API to begin transactions, something like sqlite3BtreeBeginTrans @@ -635,7 +635,7 @@ impl Pager { Ok(CursorResult::Ok(self.wal.borrow_mut().begin_write_tx()?)) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn end_tx( &self, rollback: bool, @@ -671,14 +671,14 @@ impl Pager { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn end_read_tx(&self) -> Result<()> { self.wal.borrow().end_read_tx()?; Ok(()) } /// Reads a page from the database. - #[tracing::instrument(skip_all, level = Level::DEBUG)] + #[tracing::instrument(skip_all, level = Level::INFO)] pub fn read_page(&self, page_idx: usize) -> Result { tracing::trace!("read_page(page_idx = {})", page_idx); let mut page_cache = self.page_cache.write(); @@ -765,7 +765,7 @@ impl Pager { /// In the base case, it will write the dirty pages to the WAL and then fsync the WAL. /// If the WAL size is over the checkpoint threshold, it will checkpoint the WAL to /// the database file and then fsync the database file. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn cacheflush(&self, wal_checkpoint_disabled: bool) -> Result { let mut checkpoint_result = CheckpointResult::default(); loop { @@ -849,7 +849,7 @@ impl Pager { )) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn wal_get_frame( &self, frame_no: u32, @@ -865,12 +865,12 @@ impl Pager { ) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO, target = "pager_checkpoint",)] pub fn checkpoint(&self) -> Result { let mut checkpoint_result = CheckpointResult::default(); loop { let state = *self.checkpoint_state.borrow(); - trace!("pager_checkpoint(state={:?})", state); + trace!(?state); match state { CheckpointState::Checkpoint => { let in_flight = self.checkpoint_inflight.clone(); @@ -942,7 +942,7 @@ impl Pager { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn wal_checkpoint(&self, wal_checkpoint_disabled: bool) -> Result { if wal_checkpoint_disabled { return Ok(CheckpointResult { @@ -976,7 +976,7 @@ impl Pager { // Providing a page is optional, if provided it will be used to avoid reading the page from disk. // This is implemented in accordance with sqlite freepage2() function. - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn free_page(&self, page: Option, page_id: usize) -> Result<()> { tracing::trace!("free_page(page_id={})", page_id); const TRUNK_PAGE_HEADER_SIZE: usize = 8; @@ -1048,7 +1048,7 @@ impl Pager { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn allocate_page1(&self) -> Result> { let state = self.allocate_page1_state.borrow().clone(); match state { @@ -1124,7 +1124,7 @@ impl Pager { */ // FIXME: handle no room in page cache #[allow(clippy::readonly_write_lock)] - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn allocate_page(&self) -> Result { let old_db_size = header_accessor::get_database_size(self)?; #[allow(unused_mut)] @@ -1209,7 +1209,7 @@ impl Pager { (page_size - reserved_space) as usize } - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] pub fn rollback(&self, change_schema: bool, connection: &Connection) -> Result<(), LimboError> { tracing::debug!(change_schema); self.dirty_pages.borrow_mut().clear(); diff --git a/core/storage/sqlite3_ondisk.rs b/core/storage/sqlite3_ondisk.rs index 0c3cd99b5..f9fcacb77 100644 --- a/core/storage/sqlite3_ondisk.rs +++ b/core/storage/sqlite3_ondisk.rs @@ -727,7 +727,7 @@ impl PageContent { } } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] pub fn begin_read_page( db_file: Arc, buffer_pool: Arc, @@ -774,7 +774,7 @@ pub fn finish_read_page( Ok(()) } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] pub fn begin_write_btree_page( pager: &Pager, page: &PageRef, @@ -817,7 +817,7 @@ pub fn begin_write_btree_page( res } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] pub fn begin_sync(db_file: Arc, syncing: Rc>) -> Result<()> { assert!(!*syncing.borrow()); *syncing.borrow_mut() = true; @@ -1489,7 +1489,7 @@ pub fn begin_read_wal_frame( Ok(c) } -#[instrument(err,skip(io, page, write_counter, wal_header, checksums), level = Level::TRACE)] +#[instrument(err,skip(io, page, write_counter, wal_header, checksums), level = Level::INFO)] #[allow(clippy::too_many_arguments)] pub fn begin_write_wal_frame( io: &Arc, diff --git a/core/storage/wal.rs b/core/storage/wal.rs index adfdbbfa9..7b9bdb447 100644 --- a/core/storage/wal.rs +++ b/core/storage/wal.rs @@ -499,7 +499,7 @@ impl fmt::Debug for WalFileShared { impl Wal for WalFile { /// Begin a read transaction. - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn begin_read_tx(&mut self) -> Result { let max_frame_in_wal = self.get_shared().max_frame.load(Ordering::SeqCst); @@ -565,7 +565,7 @@ impl Wal for WalFile { /// End a read transaction. #[inline(always)] - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn end_read_tx(&self) -> Result { tracing::debug!("end_read_tx(lock={})", self.max_frame_read_lock_index); let read_lock = &mut self.get_shared().read_locks[self.max_frame_read_lock_index]; @@ -574,7 +574,7 @@ impl Wal for WalFile { } /// Begin a write transaction - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn begin_write_tx(&mut self) -> Result { let busy = !self.get_shared().write_lock.write(); tracing::debug!("begin_write_transaction(busy={})", busy); @@ -585,7 +585,7 @@ impl Wal for WalFile { } /// End a write transaction - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn end_write_tx(&self) -> Result { tracing::debug!("end_write_txn"); self.get_shared().write_lock.unlock(); @@ -593,7 +593,7 @@ impl Wal for WalFile { } /// Find the latest frame containing a page. - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn find_frame(&self, page_id: u64) -> Result> { let shared = self.get_shared(); let frames = shared.frame_cache.lock(); @@ -611,7 +611,7 @@ impl Wal for WalFile { } /// Read a frame from the WAL. - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn read_frame(&self, frame_id: u64, page: PageRef, buffer_pool: Arc) -> Result<()> { tracing::debug!("read_frame({})", frame_id); let offset = self.frame_offset(frame_id); @@ -630,7 +630,7 @@ impl Wal for WalFile { Ok(()) } - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn read_frame_raw( &self, frame_id: u64, @@ -657,7 +657,7 @@ impl Wal for WalFile { } /// Write a frame to the WAL. - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn append_frame( &mut self, page: PageRef, @@ -702,14 +702,14 @@ impl Wal for WalFile { Ok(()) } - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn should_checkpoint(&self) -> bool { let shared = self.get_shared(); let frame_id = shared.max_frame.load(Ordering::SeqCst) as usize; frame_id >= self.checkpoint_threshold } - #[instrument(skip_all, level = Level::DEBUG)] + #[instrument(skip_all, level = Level::INFO)] fn checkpoint( &mut self, pager: &Pager, @@ -873,7 +873,7 @@ impl Wal for WalFile { } } - #[instrument(err, skip_all, level = Level::DEBUG)] + #[instrument(err, skip_all, level = Level::INFO)] fn sync(&mut self) -> Result { match self.sync_state.get() { SyncState::NotSyncing => { @@ -915,7 +915,7 @@ impl Wal for WalFile { self.min_frame } - #[instrument(err, skip_all, level = Level::DEBUG)] + #[instrument(err, skip_all, level = Level::INFO)] fn rollback(&mut self) -> Result<()> { // TODO(pere): have to remove things from frame_cache because they are no longer valid. // TODO(pere): clear page cache in pager. @@ -941,7 +941,7 @@ impl Wal for WalFile { Ok(()) } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] fn finish_append_frames_commit(&mut self) -> Result<()> { let shared = self.get_shared(); shared.max_frame.store(self.max_frame, Ordering::SeqCst); diff --git a/core/translate/compound_select.rs b/core/translate/compound_select.rs index fad19baec..d7e6f4689 100644 --- a/core/translate/compound_select.rs +++ b/core/translate/compound_select.rs @@ -11,7 +11,7 @@ use turso_sqlite3_parser::ast::{CompoundOperator, SortOrder}; use tracing::Level; -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] pub fn emit_program_for_compound_select( program: &mut ProgramBuilder, plan: Plan, diff --git a/core/translate/emitter.rs b/core/translate/emitter.rs index 17540ac3a..0d0c51432 100644 --- a/core/translate/emitter.rs +++ b/core/translate/emitter.rs @@ -198,7 +198,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)] +#[instrument(skip_all, level = Level::INFO)] pub fn emit_program( program: &mut ProgramBuilder, plan: Plan, @@ -216,7 +216,7 @@ pub fn emit_program( } } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] fn emit_program_for_select( program: &mut ProgramBuilder, mut plan: SelectPlan, @@ -255,7 +255,7 @@ fn emit_program_for_select( Ok(()) } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] pub fn emit_query<'a>( program: &mut ProgramBuilder, plan: &'a mut SelectPlan, @@ -395,7 +395,7 @@ pub fn emit_query<'a>( Ok(t_ctx.reg_result_cols_start.unwrap()) } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] fn emit_program_for_delete( program: &mut ProgramBuilder, plan: DeletePlan, @@ -580,7 +580,7 @@ fn emit_delete_insns( Ok(()) } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] fn emit_program_for_update( program: &mut ProgramBuilder, mut plan: UpdatePlan, @@ -699,7 +699,7 @@ fn emit_program_for_update( Ok(()) } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] fn emit_update_insns( plan: &UpdatePlan, t_ctx: &TranslateCtx, diff --git a/core/translate/expr.rs b/core/translate/expr.rs index b64a14b64..fe78275c7 100644 --- a/core/translate/expr.rs +++ b/core/translate/expr.rs @@ -27,7 +27,7 @@ pub struct ConditionMetadata { pub jump_target_when_false: BranchOffset, } -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] fn emit_cond_jump(program: &mut ProgramBuilder, cond_meta: ConditionMetadata, reg: usize) { if cond_meta.jump_if_condition_is_true { program.emit_insn(Insn::If { @@ -131,7 +131,7 @@ macro_rules! expect_arguments_even { }}; } -#[instrument(skip(program, referenced_tables, expr, resolver), level = Level::TRACE)] +#[instrument(skip(program, referenced_tables, expr, resolver), level = Level::INFO)] pub fn translate_condition_expr( program: &mut ProgramBuilder, referenced_tables: &TableReferences, diff --git a/core/translate/mod.rs b/core/translate/mod.rs index b7c82d585..c42f1d771 100644 --- a/core/translate/mod.rs +++ b/core/translate/mod.rs @@ -53,7 +53,7 @@ use transaction::{translate_tx_begin, translate_tx_commit}; use turso_sqlite3_parser::ast::{self, Delete, Insert}; use update::translate_update; -#[instrument(skip_all, level = Level::TRACE)] +#[instrument(skip_all, level = Level::INFO)] #[allow(clippy::too_many_arguments)] pub fn translate( schema: &Schema, diff --git a/core/vdbe/builder.rs b/core/vdbe/builder.rs index 7d45c5f4b..b1a9a44c7 100644 --- a/core/vdbe/builder.rs +++ b/core/vdbe/builder.rs @@ -291,7 +291,7 @@ impl ProgramBuilder { }); } - #[instrument(skip(self), level = Level::TRACE)] + #[instrument(skip(self), level = Level::INFO)] 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 diff --git a/core/vdbe/mod.rs b/core/vdbe/mod.rs index 1751ba697..4f418efe2 100644 --- a/core/vdbe/mod.rs +++ b/core/vdbe/mod.rs @@ -368,7 +368,7 @@ pub struct Program { } impl Program { - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn step( &self, state: &mut ProgramState, @@ -399,7 +399,7 @@ impl Program { } } - #[instrument(skip_all, level = Level::TRACE)] + #[instrument(skip_all, level = Level::INFO)] pub fn commit_txn( &self, pager: Rc, @@ -465,7 +465,7 @@ impl Program { } } - #[instrument(skip(self, pager, connection), level = Level::TRACE)] + #[instrument(skip(self, pager, connection), level = Level::INFO)] fn step_end_write_txn( &self, pager: &Rc, @@ -564,7 +564,7 @@ fn make_record(registers: &[Register], start_reg: &usize, count: &usize) -> Immu ImmutableRecord::from_registers(regs, regs.len()) } -#[instrument(skip(program), level = Level::TRACE)] +#[instrument(skip(program), level = Level::INFO)] fn trace_insn(program: &Program, addr: InsnReference, insn: &Insn) { if !tracing::enabled!(tracing::Level::TRACE) { return; diff --git a/simulator/generation/property.rs b/simulator/generation/property.rs index aa10fd735..50e574e86 100644 --- a/simulator/generation/property.rs +++ b/simulator/generation/property.rs @@ -485,7 +485,6 @@ impl Property { message: "fault occured".to_string(), func: Box::new(move |stack, env| { let last = stack.last().unwrap(); - dbg!(&last); match last { Ok(_) => { query_clone.shadow(env);