diff --git a/docs/project_docs/startup-profile-breakdown/plan.md b/docs/project_docs/startup-profile-breakdown/plan.md new file mode 100644 index 0000000..16ac5a4 --- /dev/null +++ b/docs/project_docs/startup-profile-breakdown/plan.md @@ -0,0 +1,20 @@ +# startup-profile-breakdown Plan + +## Goal + +`--startup-profile` のログで `create-terminal` の内訳を確認できるようにする。 + +## Scope + +- `create-terminal` を内部的に 2 段へ分解 + - terminal build + - raw mode enter +- startup profile ログに細分化した時間を出力 +- 既存の TUI 起動挙動は変えない + +## Tests + +- `test/ceeker/tui/input_test.clj` + - `create-terminal-profile` が build/raw-mode/total を返すこと +- `test/ceeker/tui/app_test.clj` + - startup profile ログに細分化した項目が出ること diff --git a/src/ceeker/tui/app.clj b/src/ceeker/tui/app.clj index 95feb97..d31ac4c 100644 --- a/src/ceeker/tui/app.clj +++ b/src/ceeker/tui/app.clj @@ -143,13 +143,21 @@ (defn- log-startup-profile! "Logs startup profiling summary to stderr." - [{:keys [create-terminal create-watcher + [{:keys [create-terminal-build + create-terminal-enter-raw-mode + create-terminal-total + create-watcher start-pane-checker total]}] (binding [*out* *err*] (println (str "ceeker: startup-profile " - "create-terminal=" - (format "%.2fms" create-terminal) + "create-terminal.build=" + (format "%.2fms" create-terminal-build) + " create-terminal.enter-raw-mode=" + (format "%.2fms" + create-terminal-enter-raw-mode) + " create-terminal.total=" + (format "%.2fms" create-terminal-total) " create-watcher=" (format "%.2fms" create-watcher) " start-pane-checker=" @@ -163,18 +171,21 @@ "Creates startup resources and optionally logs timings." [state-dir startup-profile?] (let [started-at (System/nanoTime) - terminal-step (timed-step input/create-terminal) + terminal-step (input/create-terminal-profile) watcher-step (timed-step #(create-watcher-for state-dir)) checker-step (timed-step #(start-pane-checker! state-dir))] (when startup-profile? (log-startup-profile! - {:create-terminal (:elapsed-ms terminal-step) + {:create-terminal-build (:build-ms terminal-step) + :create-terminal-enter-raw-mode + (:enter-raw-mode-ms terminal-step) + :create-terminal-total (:total-ms terminal-step) :create-watcher (:elapsed-ms watcher-step) :start-pane-checker (:elapsed-ms checker-step) :total (elapsed-ms started-at)})) - {:terminal (:result terminal-step) + {:terminal (:terminal terminal-step) :watcher (:result watcher-step) :stop-ch (:result checker-step)})) diff --git a/src/ceeker/tui/input.clj b/src/ceeker/tui/input.clj index e74ca4d..b5e31e7 100644 --- a/src/ceeker/tui/input.clj +++ b/src/ceeker/tui/input.clj @@ -3,15 +3,43 @@ (:import [org.jline.terminal TerminalBuilder] [org.jline.utils NonBlockingReader])) +(defn- elapsed-ms + "Returns elapsed milliseconds since started-at." + [started-at] + (/ (- (System/nanoTime) started-at) 1000000.0)) + +(defn build-terminal + "Builds the system terminal." + [] + (-> (TerminalBuilder/builder) + (.system true) + (.jansi false) + (.build))) + +(defn enter-raw-mode! + "Puts terminal into raw mode." + [^org.jline.terminal.Terminal terminal] + (.enterRawMode terminal) + terminal) + +(defn create-terminal-profile + "Creates a terminal and returns step timings." + [] + (let [started-at (System/nanoTime) + build-started-at (System/nanoTime) + terminal (build-terminal) + build-ms (elapsed-ms build-started-at) + raw-started-at (System/nanoTime)] + (enter-raw-mode! terminal) + {:terminal terminal + :build-ms build-ms + :enter-raw-mode-ms (elapsed-ms raw-started-at) + :total-ms (elapsed-ms started-at)})) + (defn create-terminal "Creates a JLine3 terminal and enters raw mode." [] - (let [terminal (-> (TerminalBuilder/builder) - (.system true) - (.jansi false) - (.build))] - (.enterRawMode terminal) - terminal)) + (:terminal (create-terminal-profile))) (defn- read-escape-seq "Reads an escape sequence from reader. Returns keyword or nil." diff --git a/test/ceeker/tui/app_test.clj b/test/ceeker/tui/app_test.clj index df62b0e..8c7aa20 100644 --- a/test/ceeker/tui/app_test.clj +++ b/test/ceeker/tui/app_test.clj @@ -344,8 +344,12 @@ (fn [_] :stop-ch) ceeker.tui.app/tui-loop (fn [& _]) - ceeker.tui.input/create-terminal - (fn [] :terminal) + ceeker.tui.input/create-terminal-profile + (fn [] + {:terminal :terminal + :build-ms 12.0 + :enter-raw-mode-ms 34.0 + :total-ms 46.0}) ceeker.tui.input/close-terminal (fn [_]) ceeker.tui.watcher/close-watcher @@ -355,7 +359,10 @@ (app/start-tui! nil {:startup-profile true}))) (let [output (str err)] (is (str/includes? output "ceeker: startup-profile")) - (is (str/includes? output "create-terminal=")) + (is (str/includes? output "create-terminal.build=")) + (is (str/includes? output + "create-terminal.enter-raw-mode=")) + (is (str/includes? output "create-terminal.total=")) (is (str/includes? output "create-watcher=")) (is (str/includes? output "start-pane-checker=")) (is (str/includes? output "total=")))))) @@ -370,8 +377,12 @@ (fn [_] :stop-ch) ceeker.tui.app/tui-loop (fn [& _]) - ceeker.tui.input/create-terminal - (fn [] :terminal) + ceeker.tui.input/create-terminal-profile + (fn [] + {:terminal :terminal + :build-ms 12.0 + :enter-raw-mode-ms 34.0 + :total-ms 46.0}) ceeker.tui.input/close-terminal (fn [_]) ceeker.tui.watcher/close-watcher @@ -466,8 +477,12 @@ (fn [_] nil) ceeker.tui.app/start-pane-checker! (fn [_] stop-ch) - ceeker.tui.input/create-terminal - (fn [] ::terminal) + ceeker.tui.input/create-terminal-profile + (fn [] + {:terminal ::terminal + :build-ms 1.0 + :enter-raw-mode-ms 2.0 + :total-ms 3.0}) ceeker.tui.input/close-terminal (fn [_]) ceeker.tui.watcher/close-watcher diff --git a/test/ceeker/tui/input_test.clj b/test/ceeker/tui/input_test.clj new file mode 100644 index 0000000..533f9fa --- /dev/null +++ b/test/ceeker/tui/input_test.clj @@ -0,0 +1,26 @@ +(ns ceeker.tui.input-test + (:require [ceeker.tui.input :as input] + [clojure.test :refer [deftest is testing]])) + +(deftest test-create-terminal-profile-returns-breakdown + (testing "create-terminal-profile reports build/raw-mode/total" + (let [events (atom []) + terminal ::terminal] + (with-redefs [ceeker.tui.input/build-terminal + (fn [] + (swap! events conj :build) + terminal) + ceeker.tui.input/enter-raw-mode! + (fn [t] + (swap! events conj [:raw-mode t]) + t)] + (let [profile (input/create-terminal-profile)] + (is (= terminal (:terminal profile))) + (is (number? (:build-ms profile))) + (is (number? (:enter-raw-mode-ms profile))) + (is (number? (:total-ms profile))) + (is (<= 0.0 (:build-ms profile))) + (is (<= 0.0 (:enter-raw-mode-ms profile))) + (is (<= 0.0 (:total-ms profile))) + (is (= [:build [:raw-mode terminal]] + @events)))))))