Skip to content

Commit 4c2e6e1

Browse files
authored
feat(editor): show server time and fetch time separately in result status bar (#990) (#1021)
* feat(editor): show server time and fetch time breakdown in result status bar * fix(editor): compute consistent total in timing tooltip, revert setup.ts, and ignore volatile timing in golden captures * fix(editor): preserve frontend total duration in timing tooltip and deduplicate timing split helper
1 parent a84838e commit 4c2e6e1

27 files changed

Lines changed: 423 additions & 18 deletions

File tree

‎src-tauri/src/drivers/common.rs‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -13,10 +13,10 @@ pub use blob::{
1313
};
1414
pub use pooled::DetachOnDrop;
1515
pub use query::{
16-
build_paginated_query, calculate_offset, extract_user_limit, extract_user_offset,
17-
is_explainable_query,
18-
is_select_query, returns_result_set, strip_leading_sql_comments, strip_limit_offset,
19-
transaction_effect, TransactionEffect,
16+
build_paginated_query, calculate_offset, calculate_query_timing,
17+
calculate_query_timing_from_start, extract_user_limit, extract_user_offset,
18+
is_explainable_query, is_select_query, returns_result_set, strip_leading_sql_comments,
19+
strip_limit_offset, transaction_effect, TransactionEffect,
2020
};
2121
pub use routines::{
2222
generic_drop_routine_sql, generic_routine_call_sql, quote_qualified, render_sql_literal,

‎src-tauri/src/drivers/common/query.rs‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -582,3 +582,28 @@ fn leading_keywords(query: &str, n: usize) -> Vec<String> {
582582
}
583583
words
584584
}
585+
586+
/// Calculates `(server_time_ms, fetch_time_ms)` from the total elapsed time and
587+
/// the optional elapsed time until the first row was received.
588+
///
589+
/// If no rows were received (`first_row_elapsed_ms` is `None`), server execution
590+
/// time equals the total elapsed time, and fetch time is 0.0.
591+
pub fn calculate_query_timing(
592+
total_elapsed_ms: f64,
593+
first_row_elapsed_ms: Option<f64>,
594+
) -> (Option<f64>, Option<f64>) {
595+
match first_row_elapsed_ms {
596+
Some(s_ms) => (Some(s_ms), Some((total_elapsed_ms - s_ms).max(0.0))),
597+
None => (Some(total_elapsed_ms), Some(0.0)),
598+
}
599+
}
600+
601+
/// Computes query timing given a `start_instant` and the optional
602+
/// first-row arrival time.
603+
pub fn calculate_query_timing_from_start(
604+
start_instant: std::time::Instant,
605+
first_row_elapsed_ms: Option<f64>,
606+
) -> (Option<f64>, Option<f64>) {
607+
let total_elapsed_ms = start_instant.elapsed().as_secs_f64() * 1000.0;
608+
calculate_query_timing(total_elapsed_ms, first_row_elapsed_ms)
609+
}

‎src-tauri/src/drivers/common/tests.rs‎

Lines changed: 25 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,8 @@
11
use super::{
2-
build_paginated_query, decode_blob_wire_format, encode_blob, encode_blob_full, i64_to_json,
3-
is_explainable_query, is_select_query, parse_unsafe_bigint_string, strip_leading_sql_comments,
4-
strip_limit_offset, transaction_effect, u64_to_json, TransactionEffect, DEFAULT_MAX_BLOB_SIZE,
2+
build_paginated_query, calculate_query_timing, calculate_query_timing_from_start,
3+
decode_blob_wire_format, encode_blob, encode_blob_full, i64_to_json, is_explainable_query,
4+
is_select_query, parse_unsafe_bigint_string, strip_leading_sql_comments, strip_limit_offset,
5+
transaction_effect, u64_to_json, TransactionEffect, DEFAULT_MAX_BLOB_SIZE,
56
JS_MAX_SAFE_INTEGER, JS_MAX_SAFE_UINT, MAX_BLOB_PREVIEW_SIZE,
67
};
78

@@ -867,6 +868,27 @@ fn transaction_effect_ignores_ordinary_statements() {
867868
}
868869
}
869870

871+
#[test]
872+
fn test_calculate_query_timing_with_rows() {
873+
let (server, fetch) = calculate_query_timing(50.0, Some(20.0));
874+
assert_eq!(server, Some(20.0));
875+
assert_eq!(fetch, Some(30.0));
876+
}
877+
878+
#[test]
879+
fn test_calculate_query_timing_no_rows() {
880+
let (server, fetch) = calculate_query_timing(50.0, None);
881+
assert_eq!(server, Some(50.0));
882+
assert_eq!(fetch, Some(0.0));
883+
}
884+
885+
#[test]
886+
fn test_calculate_query_timing_fetch_non_negative() {
887+
let (server, fetch) = calculate_query_timing(50.0, Some(55.0));
888+
assert_eq!(server, Some(55.0));
889+
assert_eq!(fetch, Some(0.0));
890+
}
891+
870892
#[test]
871893
fn transaction_effect_sees_through_leading_comments() {
872894
assert_eq!(

‎src-tauri/src/drivers/mysql/mod.rs‎

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1407,6 +1407,8 @@ async fn exec_on_mysql_conn(
14071407
truncated: false,
14081408
pagination: None,
14091409
additional_results: None,
1410+
server_time_ms: None,
1411+
fetch_time_ms: None,
14101412
});
14111413
}
14121414

@@ -1428,6 +1430,8 @@ async fn exec_on_mysql_conn(
14281430
truncated: false,
14291431
pagination: None,
14301432
additional_results: None,
1433+
server_time_ms: None,
1434+
fetch_time_ms: None,
14311435
});
14321436
}
14331437

@@ -1460,6 +1464,9 @@ async fn exec_on_mysql_conn(
14601464
// terminator per result set, which the collector folds into discrete sets.
14611465
let mut collector = multi_result::ResultSetCollector::new(manual_limit);
14621466

1467+
let start_instant = std::time::Instant::now();
1468+
let mut server_time_ms: Option<f64> = None;
1469+
14631470
// Scope the stream so `conn` borrow is released before returning
14641471
{
14651472
use futures::stream::StreamExt;
@@ -1471,6 +1478,9 @@ async fn exec_on_mysql_conn(
14711478
};
14721479

14731480
while let Some(result) = event_stream.next().await {
1481+
if server_time_ms.is_none() {
1482+
server_time_ms = Some(start_instant.elapsed().as_secs_f64() * 1000.0);
1483+
}
14741484
match result {
14751485
Ok(sqlx::Either::Left(_)) => collector.end_result_set(),
14761486
Ok(sqlx::Either::Right(row)) => {
@@ -1501,6 +1511,9 @@ async fn exec_on_mysql_conn(
15011511
}
15021512
} // event_stream dropped here — conn borrow released
15031513

1514+
let (server_time, fetch_time) =
1515+
crate::drivers::common::calculate_query_timing_from_start(start_instant, server_time_ms);
1516+
15041517
let mut result_sets = collector.finish();
15051518
let primary = if result_sets.is_empty() {
15061519
multi_result::ResultSetData::default()
@@ -1525,6 +1538,8 @@ async fn exec_on_mysql_conn(
15251538
truncated: set.truncated,
15261539
pagination: None,
15271540
additional_results: None,
1541+
server_time_ms: None,
1542+
fetch_time_ms: None,
15281543
})
15291544
.collect(),
15301545
)
@@ -1547,6 +1562,8 @@ async fn exec_on_mysql_conn(
15471562
truncated,
15481563
pagination,
15491564
additional_results,
1565+
server_time_ms: server_time,
1566+
fetch_time_ms: fetch_time,
15501567
})
15511568
}
15521569

‎src-tauri/src/drivers/postgres/mod.rs‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1090,6 +1090,8 @@ async fn exec_on_pg_client(
10901090
truncated: false,
10911091
pagination: None,
10921092
additional_results: None,
1093+
server_time_ms: None,
1094+
fetch_time_ms: None,
10931095
});
10941096
}
10951097

@@ -1106,6 +1108,9 @@ async fn exec_on_pg_client(
11061108
(query.to_string(), None)
11071109
};
11081110

1111+
let start_instant = std::time::Instant::now();
1112+
let mut server_time_ms: Option<f64> = None;
1113+
11091114
let pg_params: Vec<i32> = vec![];
11101115
let mut rows_stream = std::pin::pin!(client
11111116
.query_raw(&final_query, &pg_params)
@@ -1118,6 +1123,9 @@ async fn exec_on_pg_client(
11181123
use futures::stream::StreamExt;
11191124

11201125
while let Some(result) = rows_stream.next().await {
1126+
if server_time_ms.is_none() {
1127+
server_time_ms = Some(start_instant.elapsed().as_secs_f64() * 1000.0);
1128+
}
11211129
match result {
11221130
Ok(row) => {
11231131
if columns.is_empty() {
@@ -1142,6 +1150,9 @@ async fn exec_on_pg_client(
11421150
}
11431151
}
11441152

1153+
let (server_time, fetch_time) =
1154+
crate::drivers::common::calculate_query_timing_from_start(start_instant, server_time_ms);
1155+
11451156
let pagination = if let Some((page_size, p)) = pagination_meta {
11461157
let has_more = json_rows.len() > page_size as usize;
11471158
if has_more {
@@ -1165,6 +1176,8 @@ async fn exec_on_pg_client(
11651176
truncated,
11661177
pagination,
11671178
additional_results: None,
1179+
server_time_ms: server_time,
1180+
fetch_time_ms: fetch_time,
11681181
})
11691182
}
11701183

‎src-tauri/src/drivers/sqlite/mod.rs‎

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -666,6 +666,8 @@ async fn exec_on_sqlite_conn(
666666
truncated: false,
667667
pagination: None,
668668
additional_results: None,
669+
server_time_ms: None,
670+
fetch_time_ms: None,
669671
});
670672
}
671673

@@ -692,6 +694,8 @@ async fn exec_on_sqlite_conn(
692694
}
693695

694696
// Streaming
697+
let start_instant = std::time::Instant::now();
698+
let mut server_time_ms: Option<f64> = None;
695699
let mut rows_stream = sqlx::query(&final_query).fetch(&mut *conn);
696700

697701
let mut columns: Vec<String> = Vec::new();
@@ -701,6 +705,9 @@ async fn exec_on_sqlite_conn(
701705
use futures::stream::StreamExt;
702706

703707
while let Some(result) = rows_stream.next().await {
708+
if server_time_ms.is_none() {
709+
server_time_ms = Some(start_instant.elapsed().as_secs_f64() * 1000.0);
710+
}
704711
match result {
705712
Ok(row) => {
706713
if columns.is_empty() {
@@ -725,6 +732,9 @@ async fn exec_on_sqlite_conn(
725732
}
726733
}
727734

735+
let (server_time, fetch_time) =
736+
crate::drivers::common::calculate_query_timing_from_start(start_instant, server_time_ms);
737+
728738
// Apply LIMIT +1 result: if we got page_size+1 rows, has_more=true
729739
if let Some(ref mut p) = pagination {
730740
let has_more = json_rows.len() > p.page_size as usize;
@@ -742,6 +752,8 @@ async fn exec_on_sqlite_conn(
742752
truncated,
743753
pagination,
744754
additional_results: None,
755+
server_time_ms: server_time,
756+
fetch_time_ms: fetch_time,
745757
})
746758
}
747759

‎src-tauri/src/models.rs‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -517,6 +517,10 @@ pub struct QueryResult {
517517
/// of multi-result statements keep working unchanged.
518518
#[serde(default, skip_serializing_if = "Option::is_none")]
519519
pub additional_results: Option<Vec<QueryResult>>,
520+
#[serde(default, skip_serializing_if = "Option::is_none")]
521+
pub server_time_ms: Option<f64>,
522+
#[serde(default, skip_serializing_if = "Option::is_none")]
523+
pub fetch_time_ms: Option<f64>,
520524
}
521525

522526
/// One statement's outcome within an `execute_batch` call. Exactly one of
@@ -765,4 +769,24 @@ mod appearance_tests {
765769
let s = serde_json::to_string(&a).unwrap();
766770
assert_eq!(s, r##"{"accentColor":"#ff0000"}"##);
767771
}
772+
773+
#[test]
774+
fn query_result_roundtrip_with_timing() {
775+
let qr = QueryResult {
776+
columns: vec!["id".into()],
777+
rows: vec![vec![serde_json::json!(1)]],
778+
affected_rows: 0,
779+
truncated: false,
780+
pagination: None,
781+
additional_results: None,
782+
server_time_ms: Some(12.5),
783+
fetch_time_ms: Some(3.2),
784+
};
785+
let s = serde_json::to_string(&qr).unwrap();
786+
assert!(s.contains("server_time_ms"));
787+
assert!(s.contains("fetch_time_ms"));
788+
let back: QueryResult = serde_json::from_str(&s).unwrap();
789+
assert_eq!(back.server_time_ms, Some(12.5));
790+
assert_eq!(back.fetch_time_ms, Some(3.2));
791+
}
768792
}

‎src-tauri/tests/postgres_integration/golden.rs‎

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -172,7 +172,7 @@ async fn golden_get_triggers() {
172172
async fn golden_execute_query_all_types() {
173173
require_pg!();
174174
let params = pg_params();
175-
let result = postgres::execute_query(
175+
let mut result = postgres::execute_query(
176176
&params,
177177
"SELECT * FROM test_schema.all_types WHERE id = 1",
178178
None,
@@ -181,6 +181,8 @@ async fn golden_execute_query_all_types() {
181181
)
182182
.await
183183
.expect("execute_query");
184+
result.server_time_ms = None;
185+
result.fetch_time_ms = None;
184186
write_golden("execute_query_all_types.json", &result);
185187
assert_golden("execute_query_all_types.json", &result);
186188
}
@@ -312,7 +314,7 @@ async fn golden_get_trigger_definition() {
312314
async fn golden_execute_query_with_pagination() {
313315
require_pg!();
314316
let params = pg_params();
315-
let result = postgres::execute_query(
317+
let mut result = postgres::execute_query(
316318
&params,
317319
"SELECT id, col_text FROM test_schema.all_types ORDER BY id",
318320
Some(2),
@@ -321,6 +323,8 @@ async fn golden_execute_query_with_pagination() {
321323
)
322324
.await
323325
.expect("execute_query with pagination");
326+
result.server_time_ms = None;
327+
result.fetch_time_ms = None;
324328
write_golden("execute_query_with_pagination.json", &result);
325329
assert_golden("execute_query_with_pagination.json", &result);
326330
}
@@ -348,7 +352,7 @@ async fn golden_explain_analyze() {
348352
async fn golden_count_query() {
349353
require_pg!();
350354
let params = pg_params();
351-
let result = postgres::execute_query(
355+
let mut result = postgres::execute_query(
352356
&params,
353357
"SELECT COUNT(*) AS cnt FROM test_schema.all_types",
354358
None,
@@ -357,6 +361,8 @@ async fn golden_count_query() {
357361
)
358362
.await
359363
.expect("count query");
364+
result.server_time_ms = None;
365+
result.fetch_time_ms = None;
360366
write_golden("count_query.json", &result);
361367
assert_golden("count_query.json", &result);
362368
}

‎src/components/ui/ResultEntryContent.tsx‎

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -4,7 +4,8 @@ import { CheckCircle2 } from "lucide-react";
44
import { DataGrid, type DataGridCommandTarget } from "./DataGrid";
55
import { ErrorDisplay } from "./ErrorDisplay";
66
import { PaginationControls } from "./PaginationControls";
7-
import { formatDuration } from "../../utils/formatTime";
7+
import { formatDuration, formatTimingTooltip } from "../../utils/formatTime";
8+
import { useTimingLabels } from "../../hooks/useTimingLabels";
89
import { getStackedGridHeight } from "../../utils/multiResult";
910
import type { QueryResultEntry } from "../../types/editor";
1011

@@ -36,6 +37,7 @@ export function ResultEntryContent({
3637
onScrollTopChange,
3738
}: ResultEntryContentProps) {
3839
const { t } = useTranslation();
40+
const timingLabels = useTimingLabels();
3941

4042
if (entry.isLoading) {
4143
if (compact) {
@@ -71,14 +73,25 @@ export function ResultEntryContent({
7173
);
7274
}
7375

76+
const timingTooltip = entry.result
77+
? formatTimingTooltip(
78+
{
79+
serverTimeMs: entry.result.server_time_ms,
80+
fetchTimeMs: entry.result.fetch_time_ms,
81+
totalTimeMs: entry.executionTime,
82+
},
83+
timingLabels,
84+
) ?? undefined
85+
: undefined;
86+
7487
// A statement that returns no result set (INSERT/UPDATE/DELETE/DDL such as
7588
// CREATE/ALTER/DROP VIEW) still succeeded — surface that explicitly instead
7689
// of an empty grid with a misleading "0 rows retrieved" header.
7790
if (entry.result.columns.length === 0) {
7891
const affected = entry.result.affected_rows ?? 0;
7992
const time =
8093
entry.executionTime !== null ? (
81-
<span className="text-muted font-mono">
94+
<span className="text-muted font-mono" title={timingTooltip}>
8295
({formatDuration(entry.executionTime)})
8396
</span>
8497
) : null;
@@ -152,7 +165,10 @@ export function ResultEntryContent({
152165
count: entry.result.rows.length,
153166
})}{" "}
154167
{entry.executionTime !== null && (
155-
<span className="hidden @[400px]:inline text-muted ml-2 font-mono">
168+
<span
169+
className="hidden @[400px]:inline text-muted ml-2 font-mono"
170+
title={timingTooltip}
171+
>
156172
({formatDuration(entry.executionTime)})
157173
</span>
158174
)}

0 commit comments

Comments
 (0)