Skip to content

Commit 24a9547

Browse files
nipunn1313Convex, Inc.
authored andcommitted
Reorder and retime some startup logs so it's clearer (#25581)
Goal - final logs are listening on port from just run-local-backend ``` 2024-05-10T21:41:36.646131Z INFO common::http: Listening on http://0.0.0.0:8000 2024-05-10T21:41:36.646370Z INFO local_backend::proxy: Starting dev site proxy at 0.0.0.0:3211... 2024-05-10T21:41:36.646491Z INFO common::http: Listening on http://0.0.0.0:3211 ``` GitOrigin-RevId: 02b2f23e77193db18b1cd4640bea3f8879a3979c
1 parent 86e8ecb commit 24a9547

File tree

4 files changed

+37
-18
lines changed

4 files changed

+37
-18
lines changed

crates/application/src/table_summary_worker.rs

Lines changed: 8 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -91,7 +91,7 @@ impl<RT: Runtime> TableSummaryWorker<RT> {
9191
{
9292
return Ok(());
9393
}
94-
tracing::info!("Writing table summary");
94+
tracing::info!("Writing table summary checkpoint");
9595
let snapshot = writer.compute_from_last_checkpoint().await?;
9696
write_snapshot(self.persistence.as_ref(), &snapshot).await?;
9797
*last_write_info = Some(LastWriteInfo {
@@ -115,22 +115,20 @@ impl<RT: Runtime> TableSummaryWorker<RT> {
115115

116116
let mut last_write_info = None;
117117
loop {
118+
let result = self
119+
.checkpoint_table_summaries(&mut last_write_info, &writer)
120+
.await;
121+
if let Err(mut err) = result {
122+
report_error(&mut err);
123+
}
118124
let wait_fut = self.runtime.wait(Duration::from_secs(10)).fuse();
119125
pin_mut!(wait_fut);
120126
select_biased! {
121127
_ = cancel_fut => {
122128
tracing::info!("Shutting down table summary worker...");
123129
break;
124130
}
125-
_ = wait_fut => {
126-
let result = self.checkpoint_table_summaries(
127-
&mut last_write_info,
128-
&writer,
129-
).await;
130-
if let Err(mut err) = result {
131-
report_error(&mut err);
132-
}
133-
},
131+
_ = wait_fut => {},
134132
}
135133
}
136134
}

crates/database/src/index_workers/fast_forward.rs

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ use std::{
22
cmp::max,
33
collections::BTreeSet,
44
future::Future,
5+
time::Duration,
56
};
67

78
use async_trait::async_trait;
@@ -95,7 +96,13 @@ impl FastForwardIndexWorker {
9596
rt: RT,
9697
db: Database<RT>,
9798
) -> impl Future<Output = ()> + Send {
98-
retry_loop_expect_occs_and_overloaded("FastForwardWorker", rt, db, FastForwardIndexWorker)
99+
retry_loop_expect_occs_and_overloaded(
100+
"FastForwardWorker",
101+
rt,
102+
db,
103+
Duration::ZERO,
104+
FastForwardIndexWorker,
105+
)
99106
}
100107

101108
async fn fast_forward_loop<RT: Runtime>(

crates/database/src/index_workers/retriable_worker.rs

Lines changed: 13 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,6 @@
1+
use std::time::Duration;
2+
3+
use anyhow::Context;
14
use async_trait::async_trait;
25
use common::{
36
errors::report_error,
@@ -34,8 +37,11 @@ pub(crate) async fn retry_loop_expect_occs_and_overloaded<RT: Runtime>(
3437
name: &'static str,
3538
runtime: RT,
3639
db: Database<RT>,
40+
initial_wait: Duration,
3741
work: impl RetriableWorker<RT>,
3842
) {
43+
tracing::info!("Starting {name}");
44+
runtime.wait(initial_wait).await;
3945
retry_failures(name, runtime, db, MAX_OVERLOADED_RETRIES, work).await
4046
}
4147

@@ -49,9 +55,12 @@ async fn retry_failures<RT: Runtime>(
4955
let mut backoff = Backoff::new(*INDEX_WORKERS_INITIAL_BACKOFF, MAX_BACKOFF);
5056
let mut occ_errors = 0;
5157
let mut overloaded_errors = 0;
52-
5358
loop {
54-
if let Err(e) = work.work_loop(name, &runtime, &db, &mut backoff).await {
59+
if let Err(mut e) = work
60+
.work_loop(name, &runtime, &db, &mut backoff)
61+
.await
62+
.context(format!("{name} died"))
63+
{
5564
if e.is_occ() {
5665
occ_errors += 1;
5766
// Do not reset overloaded errors because we expect
@@ -73,11 +82,11 @@ async fn retry_failures<RT: Runtime>(
7382

7483
let expected_error = expected_occ || expected_overloaded;
7584
if !expected_error {
76-
report_error(&mut e.context(format!("{name} died")));
85+
report_error(&mut e);
7786
}
7887
let delay = runtime.with_rng(|rng| backoff.fail(rng));
7988
tracing::error!(
80-
"{name} died, num_failures: {}. Backing off for {}ms, expected: {}",
89+
"{name} died, num_failures: {}. Backing off for {}ms, expected: {}: {e:#}",
8190
backoff.failures(),
8291
delay.as_millis(),
8392
expected_error,

crates/database/src/index_workers/search_worker.rs

Lines changed: 8 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,4 +1,7 @@
1-
use std::sync::Arc;
1+
use std::{
2+
sync::Arc,
3+
time::Duration,
4+
};
25

36
use async_trait::async_trait;
47
use common::{
@@ -67,6 +70,8 @@ impl<RT: Runtime> SearchIndexWorker<RT> {
6770
"VectorFlusher",
6871
runtime.clone(),
6972
database.clone(),
73+
// Wait a bit since vector needs time to bootstrap. Makes startup logs a bit cleaner.
74+
Duration::from_secs(5),
7075
SearchIndexWorker::VectorFlusher(VectorIndexFlusher::new(
7176
runtime.clone(),
7277
database.clone(),
@@ -78,6 +83,7 @@ impl<RT: Runtime> SearchIndexWorker<RT> {
7883
"VectorCompactor",
7984
runtime.clone(),
8085
database.clone(),
86+
Duration::ZERO,
8187
SearchIndexWorker::VectorCompactor(VectorIndexCompactor::new(
8288
database.clone(),
8389
searcher,
@@ -90,6 +96,7 @@ impl<RT: Runtime> SearchIndexWorker<RT> {
9096
"SearchFlusher",
9197
runtime.clone(),
9298
database.clone(),
99+
Duration::ZERO,
93100
SearchIndexWorker::SearchFlusher(SearchIndexFlusher::new(
94101
runtime,
95102
database.clone(),
@@ -107,8 +114,6 @@ impl<RT: Runtime> SearchIndexWorker<RT> {
107114
db: &Database<RT>,
108115
backoff: &mut Backoff,
109116
) -> anyhow::Result<()> {
110-
tracing::info!("Starting {name}");
111-
112117
loop {
113118
let status = log_worker_starting(name);
114119
let (metrics, token) = match self {

0 commit comments

Comments
 (0)