Add debug-observer

interceptor/src/io/pedestal/interceptor/chain.clj

@@ -502,6 +502,8 @@
   had thrown the exception.
 
   When multiple observer functions are added, they are invoked in an unspecified order.
+
+  The [[debug-observer]] function is a useful example.
   "
   [context observer-fn]
   (update context ::observer-fn merge-observer observer-fn))

interceptor/src/io/pedestal/interceptor/chain/debug.clj

@@ -0,0 +1,129 @@
+; Copyright 2024 Nubank NA
+
+; The use and distribution terms for this software are covered by the
+; Eclipse Public License 1.0 (http://opensource.org/licenses/eclipse-1.0)
+; which can be found in the file epl-v10.html at the root of this distribution.
+;
+; By using this software in any fashion, you are agreeing to be bound by
+; the terms of this license.
+;
+; You must not remove this notice, or any other, from this software.
+
+(ns io.pedestal.interceptor.chain.debug
+  "Tools to help debug interceptor chain execution."
+  {:added "0.7.0"}
+  (:require [clojure.set :as set]
+            [io.pedestal.log :as log]))
+
+(declare delta*)
+
+(def ^:private omitted-value '...)
+
+(def default-omit-set
+  "The default key paths to be omitted when producing delta output."
+  #{[:response :body]
+    [:request :body]})
+
+
+(defn- omit-values
+  [omit-set key-path value]
+  (cond
+    (omit-set key-path)
+    omitted-value
+
+    (map? value)
+    (reduce-kv (fn [m k v]
+                 (assoc m k
+                        (omit-values omit-set (conj key-path k) v)))
+               {}
+               value)
+
+    :else
+    value))
+
+(defn- delta-maps
+  [omit-set deltas key-path original modified]
+  (let [o-keys      (-> original keys set)
+        m-keys      (-> modified keys set)
+        shared-keys (set/intersection o-keys m-keys)]
+    (reduce (fn [m k]
+              (cond
+                (and (contains? shared-keys k))
+                (delta* omit-set
+                        m
+                        (conj key-path k)
+                        (get original k)
+                        (get modified k))
+
+                (contains? m-keys k)
+                (let [key-path' (conj key-path k)]
+                  (assoc-in m [:added key-path']
+                            (omit-values omit-set key-path' (get modified k))))
+
+                :else
+                (let [key-path' (conj key-path k)]
+                  (assoc-in m [:removed key-path']
+                            (omit-values omit-set key-path' (get original k))))))
+            deltas
+            (set/union o-keys m-keys))))
+
+(defn- delta*
+  [omit-set deltas key-path original modified]
+  (cond
+    (= original modified)
+    deltas
+
+    (and (map? original) (map? modified))
+    (delta-maps omit-set deltas key-path original modified)
+
+    :else
+    (assoc-in deltas [:changed key-path]
+              (if (omit-set key-path)
+                omitted-value
+                {:from original
+                 :to   modified}))))
+
+(defn- delta
+  "Return map with keys :added, :removed, and :changed ..."
+  [omit-set original modified]
+  (delta* (or omit-set default-omit-set) {} [] original modified))
+
+(defn debug-observer
+  "Returns an observer function that logs, at debug level, the interceptor name, stage, execution id,
+  and a description of context changes.
+
+  The context changes are in the form of a map.
+  The :added key is a map of key path to added values.
+  The :removed key is a map of key path to removed values.
+  The :changed key is a map of key path to a value change, a map of :from and :to.
+
+
+  Options map:
+
+  | Key   | Type            | Description
+  |---    |---              |---
+  | :omit | set or function | Identifies key paths, as vectors, to omit in the description.
+
+
+  The :omit option is used to prevent certain key paths from appearing in the result delta; the value
+  for these is replaced with `...`.  It is typically a set, but can also be a function that accepts
+  a key path vector.
+
+  The default for :omit is `#{[:response :body] [:request :body]}`. This omits data that can be both
+  sensitive and verbose."
+  ([]
+   (debug-observer nil))
+  ([options]
+   (let [{:keys [omit changes-only?]} options
+         always? (not changes-only?)]
+     (fn [event]
+       (let [{:keys [execution-id stage interceptor-name context-in context-out]} event
+             changes? (not= context-in context-out)]
+         (when (or always? changes?)
+           (log/debug
+             :interceptor interceptor-name
+             :stage stage
+             :execution-id execution-id
+             :context-changes (when changes?
+                                (delta omit context-in context-out)))))))))
+

tests/resources/logback-test.xml

@@ -11,5 +11,6 @@
     </root>
 
     <logger name="org.eclipse.jetty.servlets.DoSFilter" level="ERROR"/>
+    <logger name="io.pedestal.interceptor.chain.debug" level="debug"/>
 
 </configuration>

tests/test/io/pedestal/interceptor/observer_test.clj

@@ -1,7 +1,21 @@
+; Copyright 2024 Nubank NA
+
+; The use and distribution terms for this software are covered by the
+; Eclipse Public License 1.0 (http://opensource.org/licenses/eclipse-1.0
+; which can be found in the file epl-v10.html at the root of this distri
+;
+; By using this software in any fashion, you are agreeing to be bound by
+; the terms of this license.
+;
+; You must not remove this notice, or any other, from this software.
+
 (ns io.pedestal.interceptor.observer-test
-  (:require [clojure.test :refer [deftest is use-fixtures]]
+  (:require [clojure.edn :as edn]
+            [clojure.test :refer [deftest is use-fixtures]]
             [io.pedestal.interceptor.chain :as chain]
+            [io.pedestal.interceptor.chain.debug :as debug]
             [clojure.core.async :refer [chan go close!]]
+            [io.pedestal.log :as log]
             [io.pedestal.test-common :refer [<!!?]]
             [io.pedestal.interceptor :refer [interceptor]]))
 
@@ -148,3 +162,41 @@
           [::middle :leave]
           [::outer :leave]]
          (names-and-stages))))
+
+(def capture-logger
+  (reify log/LoggerSource
+
+    (-level-enabled? [_ level] (= level :debug))
+
+    (-debug [_ body]
+      (swap! *events conj (edn/read-string body)))))
+
+(deftest debug-observer
+  (let [make-logger log/make-logger]
+    (with-redefs [log/make-logger (fn [logger-name]
+                                    (if (= logger-name "io.pedestal.interceptor.chain.debug")
+                                      capture-logger
+                                      (make-logger logger-name)))]
+      (execute (chain/add-observer nil (debug/debug-observer))
+               {:name  ::content-type
+                :leave #(assoc-in % [:response :headers "Content-Type"] "application/edn")}
+               {:name  ::change-status
+                :leave #(assoc-in % [:response :status] 303)}
+               {:name  ::rewrite-body
+                :leave #(assoc-in % [:response :body] "XXX")}
+               {:name  ::handler
+                :enter #(assoc % :response {:status 200 :body {:message "OK"}})})
+      (is (match?
+            '[{:interceptor     ::handler
+               :stage           :enter
+               :context-changes {:added {[:response] {:status 200
+                                                      :body   ...}}}}
+              {:interceptor     ::rewrite-body
+               :context-changes {:changed {[:response :body] ...}}}
+              {:interceptor     ::change-status
+               :stage           :leave
+               :context-changes {:changed {[:response :status] {:from 200 :to 303}}}}
+              {:interceptor     ::content-type
+               :stage           :leave
+               :context-changes {:added {[:response :headers] {"Content-Type" "application/edn"}}}}]
+            @*events)))))