test: monitor query sort performance in unit test

src/main/frontend/components/query_table.cljs

@@ -63,7 +63,8 @@
   (let [p-desc? (get-in current-block [:block/properties :query-sort-desc])
         desc? (if (some? p-desc?) p-desc? true)
         p-sort-by (keyword (get-in current-block [:block/properties :query-sort-by]))
-        nlp-date? (get-in current-block [:block/properties :query-nlp-date])
+        ;; Starting with #6105, we started putting properties under namespaces.
+        nlp-date? (get-in current-block [:block/properties :logseq.query/nlp-date])
         sort-by-column (or (some-> p-sort-by keyword)
                          (if (query-dsl/query-contains-filter? (:block/content current-block) "sort-by")
                            nil

src/main/frontend/util.cljc

@@ -1040,13 +1040,24 @@
 
 #?(:clj
    (defmacro with-time
-     "Evaluates expr and prints the time it took. Returns the value of expr and the spent time."
+     "Evaluates expr and prints the time it took. 
+      Returns the value of expr and the spent time of string in msecs."
      [expr]
      `(let [start# (cljs.core/system-time)
             ret# ~expr]
         {:result ret#
          :time (.toFixed (- (cljs.core/system-time) start#) 6)})))
 
+#?(:clj
+   (defmacro with-time-number
+     "Evaluates expr and prints the time it took. 
+      Returns the value of expr and the spent time of number in msecs."
+     [expr]
+     `(let [start# (cljs.core/system-time)
+            ret# ~expr]
+        {:result ret#
+         :time (- (cljs.core/system-time) start#)})))
+
 ;; TODO: profile and profileEnd
 
 ;; Copy from hiccup but tweaked for publish usage

src/test/frontend/components/query_table_test.cljs

@@ -1,7 +1,8 @@
 (ns frontend.components.query-table-test
   (:require [clojure.test :refer [deftest testing are]]
             [frontend.state :as state]
-            [frontend.components.query-table :as query-table]))
+            [frontend.components.query-table :as query-table]
+            [frontend.util :as util]))
 
 (deftest sort-result
   ;; Define since it's not defined
@@ -67,4 +68,18 @@
          {:sort-desc? false :sort-by-column :title}
          [{:title "圆圈"} {:title "意志"}]
          [{:title "意志"} {:title "圆圈"}])
-    (state/set-preferred-language! "en")))
+    (state/set-preferred-language! "en"))
+
+  (testing "monitor sort time"
+    (are [sort-state result _sorted-result timeout]
+         (>= timeout (:time (util/with-time-number (#'query-table/sort-result (mapv #(hash-map :block/properties %) result) sort-state))))
+      {:sort-desc? true :sort-by-column :rating}
+      [{:rating 8} {:rating 7}]
+      [{:rating 8} {:rating 7}]
+      0.1 ;; actual: ~0.05
+
+      {:sort-desc? false :sort-by-column :rating}
+      [{:rating 8} {:rating 7}]
+      [{:rating 7} {:rating 8}]
+      0.2 ;; actual: ~0.05
+      )))

src/test/frontend/format/block_test.cljs

@@ -1,7 +1,8 @@
 (ns frontend.format.block-test 
   (:require [cljs.test :refer [deftest testing are]]
             [frontend.format.block :as block]
-            [frontend.date :as date]))
+            [frontend.date :as date]
+            [frontend.util :as util]))
 
 (deftest test-normalize-date
   (testing "normalize date values"
@@ -18,6 +19,26 @@
          #{"2022-08-12T00:00:00Z"}
          "2022-08-12T00:00:00Z")))
 
+(deftest monitor-normalize-date-time
+  (testing "monitor time consumption of normalize date values"
+    (are [x _y timeout] (>= timeout (:time (util/with-time-number (block/normalize-block x true))))
+      "Aug 12th, 2022"
+      "2022-08-12T00:00:00Z"
+      5.0 ;; actual 2.2
+
+      "2022-08-12T00:00:00Z"
+      "2022-08-12T00:00:00Z"
+      500 ;; actual 125
+
+      #{"Aug 12th, 2022"}
+      "2022-08-12T00:00:00Z"
+      5.0 ;; actual 1.7
+
+      #{"2022-08-12T00:00:00Z"}
+      "2022-08-12T00:00:00Z"
+      50  ;; actual 17.0
+      )))
+
 (deftest test-normalize-percentage
   (testing "normalize percentages"
     (are [x y] (= (block/normalize-block x false) y)
@@ -33,7 +54,7 @@
          #{"50%"}
          0.5)))
 
-(deftest test-random-values
+(deftest test-normalize-random-values
   (testing "random values should not be processed"
     (are [x y] (= (block/normalize-block x false) y)
          "anreanre"
@@ -51,6 +72,30 @@
          "-%"
          "-%")))
 
+(deftest monitor-normalize-randome-values-time
+  (testing "monitor time consumption of random values should not be processed"
+    (are [x _y timeout] (>= timeout (:time (util/with-time-number (block/normalize-block x false))))
+      "anreanre"
+      "anreanre"
+      0.5 ;; actual 0.07
+
+      ""
+      ""
+      0.5 ;; actual 0.07
+
+      "a.0%"
+      "a.0%"
+      0.1 ;; actual 0.02
+
+      "%"
+      "%"
+      0.2 ;; actual 0.03
+
+      "-%"
+      "-%"
+      0.1 ;; actual 0.02
+      )))
+
 (deftest test-normalize-journal-title
   (testing "normalize journal titles"
     (are [x y] (let [f #(-> % date/normalize-journal-title str)]