Skip to content

Commit 29524ed

Browse files
refsetrefset
committed
add statement timing information next to results
1 parent 3541501 commit 29524ed

File tree

3 files changed

+70
-54
lines changed

3 files changed

+70
-54
lines changed

‎src/clj/xt_play/transactions.clj‎

Lines changed: 61 additions & 49 deletions
Original file line numberDiff line numberDiff line change
@@ -155,15 +155,22 @@
155155
(doall (mapv
156156
(fn [{:keys [system-time query txs] :as batch}]
157157
(log/debug tx-type "running batch: " batch)
158-
(try
159-
(if query
160-
(xtdb/query node txs)
161-
(xtdb/submit! node txs {:system-time system-time}))
162-
(catch Throwable ex
163-
(log/error "Exception while running transaction" (ex-message ex))
164-
{:error {:message (ex-message ex)
165-
:exception (.getClass ex)
166-
:data (ex-data ex)}})))
158+
(let [start-time (System/nanoTime)]
159+
(try
160+
(let [result (if query
161+
(xtdb/query node txs)
162+
(xtdb/submit! node txs {:system-time system-time}))
163+
elapsed-ms (Math/round (/ (- (System/nanoTime) start-time) 1000000.0))]
164+
(if query
165+
(assoc {} :result result :timing-ms elapsed-ms)
166+
(assoc result :timing-ms elapsed-ms)))
167+
(catch Throwable ex
168+
(let [elapsed-ms (Math/round (/ (- (System/nanoTime) start-time) 1000000.0))]
169+
(log/error "Exception while running transaction" (ex-message ex))
170+
{:error {:message (ex-message ex)
171+
:exception (.getClass ex)
172+
:data (ex-data ex)}
173+
:timing-ms elapsed-ms})))))
167174
tx-batches))]
168175
(log/info "run!-tx-res" tx-results)
169176
tx-results))
@@ -173,55 +180,60 @@
173180
(let [tx-in-progress? (atom false)
174181
;; Keep track of which batches have system-time
175182
batches-with-system-time (set (keep-indexed
176-
(fn [idx batch]
177-
(when (:system-time batch) idx))
178-
tx-batches))
183+
(fn [idx batch]
184+
(when (:system-time batch) idx))
185+
tx-batches))
179186
transformed (transform-statements tx-batches)
180187
res (map-indexed
181188
(fn [batch-idx txs]
182189
(let [has-system-time? (contains? batches-with-system-time batch-idx)]
183190
(->> (mapv
184191
(fn [statement]
185192
(log/debug "beta executing statement:" statement)
186-
(let [upper-stmt (str/upper-case (first statement))
193+
(let [start-time (System/nanoTime)
194+
upper-stmt (str/upper-case (first statement))
187195
is-begin? (str/includes? upper-stmt "BEGIN")
188196
is-commit? (str/includes? upper-stmt "COMMIT")
189197
;; Skip rendering BEGIN/COMMIT if they were auto-added for system-time
190-
skip-result? (and has-system-time? (or is-begin? is-commit?))]
191-
;; Check if this is a PRAGMA statement
192-
(if-let [pragma (pragma-statement? (first statement))]
193-
;; Handle PRAGMA statements
194-
(case pragma
195-
:finish-block
196-
(do
197-
(log/info "Executing PRAGMA finish_block")
198-
(.finishBlock (.getLogProcessor (db-catalog/primary-db node)))
199-
{:result [[:status] ["Block finished"]]
200-
:warnings []})
201-
;; Unknown pragma
202-
{:error {:message (str "Unknown PRAGMA: " pragma)}})
203-
;; Handle regular SQL statements
204-
(do
205-
(when is-begin?
206-
(reset! tx-in-progress? true))
207-
(try
208-
(let [[rs warnings] (xtdb/jdbc-execute! conn statement)
209-
res (xform-result rs)]
210-
(when is-commit?
211-
(reset! tx-in-progress? false))
212-
(log/info :run-with-jdbc-conn-warnings warnings)
213-
(if skip-result?
214-
nil ;; Return nil for auto-added BEGIN/COMMIT
215-
{:result res
216-
:warnings warnings}))
217-
(catch Exception ex
218-
(log/error "Exception while running statement" (ex-message ex))
219-
(when @tx-in-progress?
220-
(log/warn "Rolling back transaction")
221-
(xtdb/jdbc-execute! conn ["ROLLBACK"]))
222-
{:error {:message (ex-message ex)
223-
:exception (.getClass ex)
224-
:data (ex-data ex)}}))))))
198+
skip-result? (and has-system-time? (or is-begin? is-commit?))
199+
result
200+
;; Check if this is a PRAGMA statement
201+
(if-let [pragma (pragma-statement? (first statement))]
202+
;; Handle PRAGMA statements
203+
(case pragma
204+
:finish-block
205+
(do
206+
(log/info "Executing PRAGMA finish_block")
207+
(.finishBlock (.getLogProcessor (db-catalog/primary-db node)))
208+
{:result [[:status] ["Block finished"]]
209+
:warnings []})
210+
;; Unknown pragma
211+
{:error {:message (str "Unknown PRAGMA: " pragma)}})
212+
;; Handle regular SQL statements
213+
(do
214+
(when is-begin?
215+
(reset! tx-in-progress? true))
216+
(try
217+
(let [[rs warnings] (xtdb/jdbc-execute! conn statement)
218+
res (xform-result rs)]
219+
(when is-commit?
220+
(reset! tx-in-progress? false))
221+
(log/info :run-with-jdbc-conn-warnings warnings)
222+
(if skip-result?
223+
nil ;; Return nil for auto-added BEGIN/COMMIT
224+
{:result res
225+
:warnings warnings}))
226+
(catch Exception ex
227+
(log/error "Exception while running statement" (ex-message ex))
228+
(when @tx-in-progress?
229+
(log/warn "Rolling back transaction")
230+
(xtdb/jdbc-execute! conn ["ROLLBACK"]))
231+
{:error {:message (ex-message ex)
232+
:exception (.getClass ex)
233+
:data (ex-data ex)}}))))
234+
elapsed-ms (Math/round (/ (- (System/nanoTime) start-time) 1000000.0))]
235+
(when result
236+
(assoc result :timing-ms elapsed-ms))))
225237
txs)
226238
;; Remove nils (filtered BEGIN/COMMIT results)
227239
(remove nil?)
@@ -254,4 +266,4 @@
254266
(mapv #(update % :txs util/read-edn) tx-batches))
255267
(let [res (run!-tx node "sql"
256268
[{:txs (util/read-edn query) :query true}])]
257-
(first res)))))
269+
(:result (first res))))))

‎src/cljs/xt_play/view.cljs‎

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -261,7 +261,7 @@
261261
the-result (prune-tx-results-fn (get results position))]
262262
[spacer-header (count results)
263263
(map-indexed
264-
(fn [idx {:keys [result error warnings]}]
264+
(fn [idx {:keys [result error warnings timing-ms]}]
265265
^{:key idx}
266266
[:div {:class (if (pos? idx)
267267
"border-t-2 border-gray-100 py-2"
@@ -278,7 +278,10 @@
278278
(seq result) [display-table result (str position "-" idx)]
279279
:else no-results-message)
280280
(when (seq warnings)
281-
[display-warnings warnings])])
281+
[display-warnings warnings])
282+
(when timing-ms
283+
[:div {:class "text-right text-xs text-gray-500 pr-4 pb-2"}
284+
(str timing-ms " ms")])])
282285
the-result)]))))])))
283286

284287
(defn- rm-stmt-header [id system-time position]

‎test/clj/xt_play/xtdb_stubs.clj‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -15,15 +15,16 @@
1515

1616
(defn submit! [_node txs opts]
1717
(log/info :stub-submit-tx txs opts)
18-
(execute! txs))
18+
(execute! txs)
19+
;; Return empty map so assoc :timing-ms works
20+
{})
1921

2022
(defn query [_node q]
2123
(log/info :stub-query q)
2224
(execute! q)
2325
(or
2426
@resp
25-
[[{:xt/id 2, :col1 "bar", :col2 " baz"} {:xt/id 1, :col1 "foo"}]
26-
[]]))
27+
[{:xt/id 2, :col1 "bar", :col2 " baz"} {:xt/id 1, :col1 "foo"}]))
2728

2829
(defn jdbc-execute! [_conn statement]
2930
(log/info :stub-jdbc-execute! statement)

0 commit comments

Comments
 (0)