External Database, Phase 2¶
Let’s get the rest of the functions in the my.clojure-game-geek.db
namespace
working again and add tests for them.
We’ll do a little refactoring as well, to make both the production code
and the tests clearer and simpler.
Logging¶
It’s always a good idea to know exactly what SQL queries are executing in your application; you’ll never figure out what’s slowing down your application if you don’t know what queries are even executing.
(ns my.clojure-game-geek.db
(:require [clojure.java.jdbc :as jdbc]
[io.pedestal.log :as log]
[clojure.string :as string]
[clojure.set :as set]
[com.stuartsierra.component :as component])
(:import (com.mchange.v2.c3p0 ComboPooledDataSource)))
(defn- pooled-data-source
[host dbname user password port]
(doto (ComboPooledDataSource.)
(.setDriverClass "org.postgresql.Driver")
(.setJdbcUrl (str "jdbc:postgresql://" host ":" port "/" dbname))
(.setUser user)
(.setPassword password)))
(defrecord ClojureGameGeekDb [^ComboPooledDataSource datasource]
component/Lifecycle
(start [this]
(assoc this :datasource (pooled-data-source "localhost" "cggdb" "cgg_role" "lacinia" 25432)))
(stop [this]
(.close datasource)
(assoc this :datasource nil)))
(defn- query
[component statement]
(let [[sql & params] statement]
(log/debug :sql (string/replace sql #"\s+" " ")
:params params))
(jdbc/query component statement))
(defn- execute!
[component statement]
(let [[sql & params] statement]
(log/debug :sql (string/replace sql #"\s+" " ")
:params params))
(jdbc/execute! component statement))
We’ve introduced our own versions of clojure.java.jdbc/query
and clojure.java.jdbc/execute!
that
logs the SQL and parameters before continuing on to the standard implementation.
Because of how we format the SQL in our code, it is useful to convert the embedded newlines and indentation into single spaces.
A bit about logging: In a typical Java, or even Clojure, application the focus on logging is on a textural message for the user to read. Different developers approach this in different ways … everything from the inscrutably cryptic to the overly verbose. Yet, across that spectrum, there always an assumption that some user is reading the log.
The io.pedestal/pedestal.log
library introduces a different idea:
logs as a stream of data … a sequence of maps.
That’s what we see in the call to log/debug
: just keys and values
that are interesting.
When logged, it may look like:
DEBUG my.clojure-game-geek.db - {:sql "select game_id, name, summary, min_players, max_players, created_at, updated_at from board_game where game_id = ?", :params (1234), :line 32}
That’s the debug level and namespace, then the map of keys and values (io.pedestal.log
adds the :line
key).
The useful and interesting details are present and unambiguously formatted, since the output is not formatted specifically for a user to read.
This can be a very powerful concept; these logs can even be read back
into memory, converted back into data, and operated on with all the
map
, reduce
, and filter
power that Clojure provides. [1]
After years of sweating the details on formatting (and capitalizing, and quoting, and punctuating) human-readible error messages, it is a joy to just throw whatever data is useful into the log, and not care about all those human oriented formatting details.
This is, of course, all possible because all data in Clojure can be printed out nicely
and even read back in again.
By comparison, data values or other objects in Java
only have useful debugging output if their class provides
an override of the default toString()
method.
When it comes time to execute a query, little has changed
except that the call is now to the local query
function, not the one
provided by clojure.java.jdcb
:
(defn find-game-by-id
[component game-id]
(-> (query component
["select game_id, name, summary, min_players, max_players, created_at, updated_at
from board_game where game_id = ?" game-id])
first
remap-board-game))
logback-test.xml¶
We can enable logging, just for testing purposes, in our logback-test.xml
:
<configuration scan="true" scanPeriod="1 seconds">
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%-5level %logger - %msg%n</pattern>
</encoder>
</appender>
<root level="warn">
<appender-ref ref="STDOUT"/>
</root>
<logger name="my.clojure-game-geek.db" level="DEBUG"/>
</configuration>
Adding a <logger>
element provides an override for the namespace, so that DEBUG
level
calls will be output instead of omitted (the debug level is lower than the default warn level).
Nicely, Logback will pick up this change to the configuration file without a restart.
Re-running tests¶
If we switch back to the my.clojure-game-geek.system-test
namespace and re-run the tests,
the debug output will be mixed into the test tool output:
Loading src/my/clojure_game_geek/db.clj... done
Loading test/my/clojure_game_geek/system_test.clj... done
Running tests in my.clojure-game-geek.system-test
DEBUG my.clojure-game-geek.db - {:sql "select game_id, name, summary, min_players, max_players, created_at, updated_at from board_game where game_id = ?", :params (1234), :line 31}
Ran 1 test containing 1 assertion.
No failures.
More code updates¶
The remaining functions in my.clojure-game-geek.db
can be rewritten to make use of the
local query
and execute!
functions, operate on the real database:
(defn- remap-member
[row-data]
(set/rename-keys row-data {:member_id :id
:created_at :createdAt
:updated_at :updatedAt}))
(defn- remap-designer
[row-data]
(set/rename-keys row-data {:designer_id :id
:created_at :createdAt
:updated_at :updatedAt}))
(defn- remap-rating
[row-data]
(set/rename-keys row-data {:member_id :member-id
:game_id :game-id
:created_at :createdAt
:updated_at :updatedAt}))
(defn find-member-by-id
[component member-id]
(-> (query component
["select member_id, name, created_at, updated_at
from member
where member_id = ?" member-id])
first
remap-member))
(defn list-designers-for-game
[component game-id]
(->> (query component
["select d.designer_id, d.name, d.uri, d.created_at, d.updated_at
from designer d
inner join designer_to_game j on (d.designer_id = j.designer_id)
where j.game_id = ?
order by d.name" game-id])
(map remap-designer)))
(defn list-games-for-designer
[component designer-id]
(->> (query component
["select g.game_id, g.name, g.summary, g.min_players, g.max_players, g.created_at,
g.updated_at
from board_game g
inner join designer_to_game j on (g.game_id = j.game_id)
where j.designer_id = ?
order by g.name" designer-id])
(map remap-board-game)))
(defn list-ratings-for-game
[component game-id]
(->> (query component
["select game_id, member_id, rating, created_at, updated_at
from game_rating
where game_id = ?" game-id])
(map remap-rating)))
(defn list-ratings-for-member
[component member-id]
(->> (query component
["select game_id, member_id, rating, created_at, updated_at
from game_rating
where member_id = ?" member-id])
(map remap-rating)))
(defn upsert-game-rating
"Adds a new game rating, or changes the value of an existing game rating.
Returns nil."
[component game-id member-id rating]
(execute! component
["insert into game_rating (game_id, member_id, rating)
values (?, ?, ?)
on conflict (game_id, member_id) do update set rating = ?"
game-id member-id rating rating])
nil)
The majority of this is quite straight-forward, except for the
upsert-game-rating
function, which makes use of the SQL on conflict
clause
to handle the case where a rating already exists for a particular
game and member - what starts as an insert is converted to an update.
Summary¶
With the database enabled, it was relatively straight forward to convert the old in-memory code to make use of the real database - assuming you are up-to speed on SQL. Most importantly, none of these changes affected the calling code, the field resolvers, at all.
In the next chapter, we’ll focus on testing the code we’ve just added.
[1] | I’ve used this on another project where a bug manifested only at a large scale of operations; by hooking into Logback and capturing the logged maps, it was possible to quickly filter through megabytes of output to the find the clues that revealed how the bug occured. |