diff --git a/packages/turso-sync-engine/src/database_sync_engine.rs b/packages/turso-sync-engine/src/database_sync_engine.rs index bb0dd7264..f804a6dda 100644 --- a/packages/turso-sync-engine/src/database_sync_engine.rs +++ b/packages/turso-sync-engine/src/database_sync_engine.rs @@ -45,7 +45,7 @@ async fn update_meta( ) -> Result<()> { let mut meta = orig.as_ref().unwrap().clone(); update(&mut meta); - tracing::debug!("update_meta: {meta:?}"); + tracing::info!("update_meta: {meta:?}"); let completion = io.full_write(meta_path, meta.dump()?)?; // todo: what happen if we will actually update the metadata on disk but fail and so in memory state will not be updated wait_full_body(coro, &completion).await?; @@ -60,7 +60,7 @@ async fn set_meta( orig: &mut Option, meta: DatabaseMetadata, ) -> Result<()> { - tracing::debug!("set_meta: {meta:?}"); + tracing::info!("set_meta: {meta:?}"); let completion = io.full_write(meta_path, meta.dump()?)?; // todo: what happen if we will actually update the metadata on disk but fail and so in memory state will not be updated wait_full_body(coro, &completion).await?; @@ -103,7 +103,7 @@ impl DatabaseSyncEngine { /// This method will **not** send local changed to the remote /// This method will block writes for the period of pull pub async fn pull(&mut self, coro: &Coro) -> Result<()> { - tracing::debug!( + tracing::info!( "pull: draft={}, synced={}", self.draft_path, self.synced_path @@ -120,7 +120,6 @@ impl DatabaseSyncEngine { // we will "replay" Synced WAL to the Draft WAL later without pushing it to the remote // so, we pass 'capture: true' as we need to preserve all changes for future push of WAL let synced = self.io.open_tape(&self.synced_path, true)?; - tracing::info!("opened synced"); // we will start wal write session for Draft DB in order to hold write lock during transfer of changes let mut draft_session = WalSession::new(connect(coro, &self.draft_tape).await?); @@ -168,7 +167,7 @@ impl DatabaseSyncEngine { let WalPullResult::NeedCheckpoint = pull_result else { break; }; - tracing::debug!( + tracing::info!( "ready to checkpoint synced db file at {:?}, generation={}", self.synced_path, self.meta().synced_generation @@ -198,7 +197,7 @@ impl DatabaseSyncEngine { /// This method will **not** pull remote changes to the local DB /// This method will **not** block writes for the period of sync pub async fn push(&mut self, coro: &Coro) -> Result<()> { - tracing::debug!( + tracing::info!( "push: draft={}, synced={}", self.draft_path, self.synced_path @@ -237,7 +236,7 @@ impl DatabaseSyncEngine { } async fn init(&mut self, coro: &Coro) -> Result<()> { - tracing::debug!( + tracing::info!( "initialize sync engine: draft={}, synced={}, opts={:?}", self.draft_path, self.synced_path, @@ -258,7 +257,7 @@ impl DatabaseSyncEngine { } None => { let meta = self.bootstrap_db_files(coro).await?; - tracing::debug!("write meta after successful bootstrap: meta={meta:?}"); + tracing::info!("write meta after successful bootstrap: meta={meta:?}"); set_meta( coro, self.protocol.as_ref(), @@ -285,7 +284,7 @@ impl DatabaseSyncEngine { } async fn pull_synced_from_remote(&mut self, coro: &Coro) -> Result { - tracing::debug!( + tracing::info!( "pull_synced_from_remote: draft={:?}, synced={:?}", self.draft_path, self.synced_path, @@ -330,7 +329,7 @@ impl DatabaseSyncEngine { } async fn push_synced_to_remote(&mut self, coro: &Coro) -> Result<()> { - tracing::debug!( + tracing::info!( "push_synced_to_remote: draft={}, synced={}, id={}", self.draft_path, self.synced_path, @@ -381,7 +380,7 @@ impl DatabaseSyncEngine { self.meta.is_none(), "bootstrap_db_files must be called only when meta is not set" ); - tracing::debug!( + tracing::info!( "bootstrap_db_files: draft={}, synced={}", self.draft_path, self.synced_path, @@ -410,7 +409,7 @@ impl DatabaseSyncEngine { let db_info = db_bootstrap(coro, self.protocol.as_ref(), files).await?; let elapsed = std::time::Instant::now().duration_since(start_time); - tracing::debug!( + tracing::info!( "bootstrap_db_files: finished draft={:?}, synced={:?}: elapsed={:?}", self.draft_path, self.synced_path, @@ -428,7 +427,7 @@ impl DatabaseSyncEngine { /// Reset WAL of Synced database which potentially can have some local changes async fn reset_synced_if_dirty(&mut self, coro: &Coro) -> Result<()> { - tracing::debug!( + tracing::info!( "reset_synced: synced_path={:?}, synced_is_dirty={}", self.synced_path, self.synced_is_dirty diff --git a/packages/turso-sync-engine/src/database_sync_operations.rs b/packages/turso-sync-engine/src/database_sync_operations.rs index e9e257462..75e3fba19 100644 --- a/packages/turso-sync-engine/src/database_sync_operations.rs +++ b/packages/turso-sync-engine/src/database_sync_operations.rs @@ -122,7 +122,7 @@ pub async fn wal_pull<'a, C: ProtocolIO, U: AsyncFnMut(&'a Coro, u64) -> Result< end_frame: u64, mut update: U, ) -> Result { - tracing::debug!( + tracing::info!( "wal_pull: generation={}, start_frame={}, end_frame={}", generation, start_frame, @@ -209,7 +209,7 @@ pub async fn wal_push( end_frame: u64, ) -> Result { assert!(wal_session.in_txn()); - tracing::debug!("wal_push: baton={baton:?}, generation={generation}, start_frame={start_frame}, end_frame={end_frame}"); + tracing::info!("wal_push: baton={baton:?}, generation={generation}, start_frame={start_frame}, end_frame={end_frame}"); if start_frame == end_frame { return Ok(WalPushResult::Ok { baton: None }); @@ -272,7 +272,7 @@ pub async fn transfer_logical_changes( client_id: &str, bump_pull_gen: bool, ) -> Result<()> { - tracing::debug!("transfer_logical_changes: client_id={client_id}"); + tracing::info!("transfer_logical_changes: client_id={client_id}"); let source_conn = connect_untracked(source)?; let target_conn = connect_untracked(target)?; @@ -293,12 +293,12 @@ pub async fn transfer_logical_changes( Error::DatabaseSyncEngineError("unexpected source pull_gen type".to_string()) })?, None => { - tracing::debug!("transfer_logical_changes: client_id={client_id}, turso_sync_last_change_id table is not found"); + tracing::info!("transfer_logical_changes: client_id={client_id}, turso_sync_last_change_id table is not found"); 0 } } }; - tracing::debug!( + tracing::info!( "transfer_logical_changes: client_id={client_id}, source_pull_gen={source_pull_gen}" ); @@ -383,7 +383,7 @@ pub async fn transfer_logical_changes( } DatabaseTapeOperation::Commit => { if rows_changed > 0 || (bump_pull_gen && last_change_id.unwrap_or(0) > 0) { - tracing::debug!("prepare update stmt for turso_sync_last_change_id table with client_id={} and last_change_id={:?}", client_id, last_change_id); + tracing::info!("prepare update stmt for turso_sync_last_change_id table with client_id={} and last_change_id={:?}", client_id, last_change_id); // update turso_sync_last_change_id table with new value before commit let mut set_last_change_id_stmt = session.conn().prepare(TURSO_SYNC_UPDATE_LAST_CHANGE_ID)?; @@ -392,7 +392,7 @@ pub async fn transfer_logical_changes( } else { (source_pull_gen, last_change_id.unwrap_or(0)) }; - tracing::debug!("transfer_logical_changes: client_id={client_id}, set pull_gen={next_pull_gen}, change_id={next_change_id}, rows_changed={rows_changed}"); + tracing::info!("transfer_logical_changes: client_id={client_id}, set pull_gen={next_pull_gen}, change_id={next_change_id}, rows_changed={rows_changed}"); set_last_change_id_stmt .bind_at(1.try_into().unwrap(), Value::Integer(next_pull_gen)); set_last_change_id_stmt @@ -414,7 +414,7 @@ pub async fn transfer_logical_changes( session.replay(coro, operation).await?; } - tracing::debug!("transfer_logical_changes: rows_changed={:?}", rows_changed); + tracing::info!("transfer_logical_changes: rows_changed={:?}", rows_changed); Ok(()) } @@ -428,7 +428,7 @@ pub async fn transfer_physical_changes( source_sync_watermark: u64, target_wal_match_watermark: u64, ) -> Result { - tracing::debug!("transfer_physical_changes: source_wal_match_watermark={source_wal_match_watermark}, source_sync_watermark={source_sync_watermark}, target_wal_match_watermark={target_wal_match_watermark}"); + tracing::info!("transfer_physical_changes: source_wal_match_watermark={source_wal_match_watermark}, source_sync_watermark={source_sync_watermark}, target_wal_match_watermark={target_wal_match_watermark}"); let source_conn = connect(coro, source).await?; let mut source_session = WalSession::new(source_conn.clone()); @@ -454,7 +454,7 @@ pub async fn transfer_physical_changes( let mut last_frame_info = None; let mut frame = vec![0u8; WAL_FRAME_SIZE]; let mut target_sync_watermark = target_session.frames_count()?; - tracing::debug!( + tracing::info!( "transfer_physical_changes: start={}, end={}", source_wal_match_watermark + 1, source_frames_count @@ -465,7 +465,7 @@ pub async fn transfer_physical_changes( target_session.append_page(frame_info.page_no, &frame[WAL_FRAME_HEADER..])?; if source_frame_no == source_sync_watermark { target_sync_watermark = target_session.frames_count()? + 1; // +1 because page will be actually commited on next iteration - tracing::debug!("set target_sync_watermark to {}", target_sync_watermark); + tracing::info!("set target_sync_watermark to {}", target_sync_watermark); } last_frame_info = Some(frame_info); }