Skip to content

Ability to format logged queries #5

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

Ability to format logged queries #5

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
9bffcc7
Add :unlogged-spec for queries without logging
danielytics Sep 29, 2020
037fcb1
Add ability to customize format of logged queries
danielytics Sep 29, 2020
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
22 changes: 12 additions & 10 deletions src/duct/database/sql/hikaricp.clj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,32 +18,34 @@
(defn- logged-query [^QueryInfo query-info]
(let [query (.getQuery query-info)
params (query-parameter-lists query-info)]
(into [query] (if (= (count params) 1) (first params) params))))
(into [query] (if (= (count params) 1) (first params) params))))
Copy link
Contributor

@weavejester weavejester Dec 7, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Looks like a space was accidentally deleted here, misaligning the indentation.


(defn- logging-listener [logger]
(defn- logging-listener [logger query-formatter]
(reify QueryExecutionListener
(beforeQuery [_ _ _])
(afterQuery [_ exec-info query-infos]
(let [elapsed (.getElapsedTime exec-info)
queries (mapv logged-query query-infos)]
queries (mapv (comp (or query-formatter identity) logged-query) query-infos)]
(if (= (count queries) 1)
(log/log logger :info ::sql/query {:query (first queries), :elapsed elapsed})
(log/log logger :info ::sql/batch-query {:queries queries, :elapsed elapsed}))))))

(defn- wrap-logger [datasource logger]
(defn- wrap-logger [datasource logger query-formatter]
(doto (ProxyDataSource. datasource)
(.addListener (logging-listener logger))))
(.addListener (logging-listener logger query-formatter))))

(defn- unwrap-logger [^DataSource datasource]
(.unwrap datasource DataSource))

(defmethod ig/init-key :duct.database.sql/hikaricp
[_ {:keys [logger connection-uri jdbc-url] :as options}]
(sql/->Boundary {:datasource
(-> (dissoc options :logger)
[_ {:keys [logger connection-uri jdbc-url log-query-formatter] :as options}]
Copy link
Contributor

@weavejester weavejester Dec 7, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adding a default value for log-query-formatter as identity here would prevent a need for the (or query-formatter identity) later on.

(let [datasource (-> (dissoc options :logger)
(assoc :jdbc-url (or jdbc-url connection-uri))
(hikari-cp/make-datasource)
(cond-> logger (wrap-logger logger)))}))
(hikari-cp/make-datasource))]
(if logger
Copy link
Contributor

@weavejester weavejester Dec 7, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why use an if here, instead of tacking the extra assoc onto the end of the cond->?

Copy link
Author

@danielytics danielytics Aug 7, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the reason was so that it only runs:

(assoc boundary :unlogged-spec {:datasource datasource})

when a logger is set. Perhaps just always set unlogged-spec, regardless of if a logger is specified or not?

Something like this:

(let [datasource (-> (dissoc options :logger)
                     (assoc :jdbc-url (or jdbc-url connection-uri))
                     (hikari-cp/make-datasource))]
    (-> (sql/->Boundary {:datasource (cond-> datasource logger (wrap-logger logger log-query-formatter))})
        (assoc :unlogged-spec {:datasource datasource})))

PS: I'm not sure how you want it formatted, I'm having a hard time the wrap-logger line under 80 characters without introducing another binding in the let. Perhaps this:

(defmethod ig/init-key :duct.database.sql/hikaricp
  [_ {:keys [logger connection-uri jdbc-url log-query-formatter]
      :or {log-query-formatter identity} :as options}]
  (let [datasource (-> (dissoc options :logger)
                       (assoc :jdbc-url (or jdbc-url connection-uri))
                       (hikari-cp/make-datasource))
        logged-datasource (cond-> datasource
                            logger (wrap-logger logger log-query-formatter))]
    (assoc (sql/->Boundary {:datasource logged-datasource})
           :unlogged-spec {:datasource datasource})))

Copy link
Contributor

@weavejester weavejester Aug 9, 2021 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I see now. Then perhaps let's factor out some of this into a separate function for clarity:

(defn- logged-boundary [datasource {:keys [logger log-query-formatter]}]
  (let [logged-source (wrap-logger datasource logger log-query-formatter)]
    (-> (sql/->Boundary {:datasource logged-source})
        (assoc :unlogged-spec {:datasource datasource}))))

(defmethod ig/init-key :duct.database.sql/hikaricp
  [_ {:keys [logger connection-uri jdbc-url logger] :as options}]
  (let [datasource (-> (dissoc options :logger)
                       (assoc :jdbc-url (or jdbc-url connection-uri))
                       (hikari-cp/make-datasource))]
    (if logger
      (logged-boundary data-source options)
      (sql/->Boundary {:datasource datasource}))))

What do you think?

Copy link
Author

@danielytics danielytics Aug 12, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That looks good to me. I'll push this and the other changes soon.

(-> (sql/->Boundary {:datasource (wrap-logger datasource logger log-query-formatter)})
(assoc :unlogged-spec {:datasource datasource}))
(sql/->Boundary {:datasource datasource}))))

(defmethod ig/halt-key! :duct.database.sql/hikaricp [_ {:keys [spec]}]
(let [ds (unwrap-logger (:datasource spec))]
Expand Down
48 changes: 48 additions & 0 deletions test/duct/database/sql/hikaricp_test.clj
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -79,3 +79,51 @@
(is (not (.isClosed (unwrap-logger (:datasource spec)))))
(ig/halt-key! ::sql/hikaricp hikaricp)
(is (.isClosed (unwrap-logger (:datasource spec))))))

(deftest unlogged-test
(let [logs (atom [])
logger (->AtomLogger logs)
hikaricp (ig/init-key ::sql/hikaricp {:jdbc-url "jdbc:sqlite:" :logger logger})
spec (:unlogged-spec hikaricp)]
(jdbc/execute! spec ["CREATE TABLE foo (id INT, body TEXT)"])
(jdbc/db-do-commands spec ["INSERT INTO foo VALUES (1, 'a')"
"INSERT INTO foo VALUES (2, 'b')"])
(is (= (jdbc/query spec ["SELECT * FROM foo"])
[{:id 1, :body "a"} {:id 2, :body "b"}]))
(is (= (jdbc/query spec ["SELECT * FROM foo WHERE id = ?" 1])
[{:id 1, :body "a"}]))
(is (= (jdbc/query spec ["SELECT * FROM foo WHERE id = ? AND body = ?" 1 "a"])
[{:id 1, :body "a"}]))
(is (empty? @logs))))

(defn log-query-formatter [[query & params]]
(into
Copy link
Contributor

@weavejester weavejester Dec 7, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nonstandard indentation, and also short enough to put on one line. Could you format as:

  (into [(str (re-find #"^\w+" query) "...")] params)

[(str (re-find #"^\w+" query) "...")]
params))

(deftest formatted-logging-test
(let [logs (atom [])
logger (->AtomLogger logs)
hikaricp (ig/init-key ::sql/hikaricp {:jdbc-url "jdbc:sqlite:" :logger logger :log-query-formatter log-query-formatter})
Copy link
Contributor

@weavejester weavejester Dec 7, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Line longer than 80 characters.

spec (:spec hikaricp)]
(jdbc/execute! spec ["CREATE TABLE foo (id INT, body TEXT)"])
(jdbc/db-do-commands spec ["INSERT INTO foo VALUES (1, 'a')"
"INSERT INTO foo VALUES (2, 'b')"])
(is (= (jdbc/query spec ["SELECT * FROM foo"])
[{:id 1, :body "a"} {:id 2, :body "b"}]))
(is (= (jdbc/query spec ["SELECT * FROM foo WHERE id = ?" 1])
[{:id 1, :body "a"}]))
(is (= (jdbc/query spec ["SELECT * FROM foo WHERE id = ? AND body = ?" 1 "a"])
[{:id 1, :body "a"}]))
(is (every? nat-int? (map elapsed @logs)))
(is (= (map remove-elapsed @logs)
[[:info ::sql/query {:query ["CREATE..."]}]
[:info ::sql/batch-query {:queries [["INSERT..."]
["INSERT..."]]}]
[:info ::sql/query {:query ["SELECT..."]}]
[:info ::sql/query {:query ["SELECT..." 1]}]
[:info ::sql/query
{:query ["SELECT..." 1 "a"]}]]))
(is (not (.isClosed (unwrap-logger (:datasource spec)))))
(ig/halt-key! ::sql/hikaricp hikaricp)
(is (.isClosed (unwrap-logger (:datasource spec))))))