From ec515758da71372ce2a7614ecacbea0395a10dc2 Mon Sep 17 00:00:00 2001 From: Roman Scherer Date: Mon, 12 Jun 2023 11:28:01 +0200 Subject: [PATCH] Add CIDER log middleware --- .clj-kondo/config.edn | 1 + CHANGELOG.md | 4 + .../pages/nrepl-api/supplied_middleware.adoc | 6 + doc/modules/ROOT/pages/usage.adoc | 2 + project.clj | 7 +- src/cider/nrepl.clj | 130 ++++++ src/cider/nrepl/middleware.clj | 1 + src/cider/nrepl/middleware/log.clj | 296 ++++++++++++ test/clj/cider/nrepl/middleware/log_test.clj | 441 ++++++++++++++++++ test/resources/logback-test.xml | 16 + test/resources/logging.properties | 59 +++ 11 files changed, 962 insertions(+), 1 deletion(-) create mode 100644 src/cider/nrepl/middleware/log.clj create mode 100644 test/clj/cider/nrepl/middleware/log_test.clj create mode 100644 test/resources/logback-test.xml create mode 100644 test/resources/logging.properties diff --git a/.clj-kondo/config.edn b/.clj-kondo/config.edn index 3122f411..faafa4ba 100644 --- a/.clj-kondo/config.edn +++ b/.clj-kondo/config.edn @@ -1,5 +1,6 @@ {:hooks {:analyze-call {cider.nrepl.middleware.out/with-out-binding hooks.core/with-out-binding}} + :lint-as {cider.nrepl.middleware.log-test/with-each-framework clojure.core/let} :linters {:unresolved-symbol {:exclude [(cider.nrepl/def-wrapper) (cider.nrepl.middleware.util.instrument/definstrumenter) (cider.nrepl.middleware.util.instrument/with-break) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2a1a65a8..98a40f8e 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,10 @@ ## master (unreleased) +### New features + +* [#773](https://github.com/clojure-emacs/cider-nrepl/pull/773) Add middleware to capture, debug, inspect and view log events emitted by Java logging frameworks. + ### Changes * Bump `orchard` to 0.12.0. diff --git a/doc/modules/ROOT/pages/nrepl-api/supplied_middleware.adoc b/doc/modules/ROOT/pages/nrepl-api/supplied_middleware.adoc index 5a3d9b29..f35212c0 100644 --- a/doc/modules/ROOT/pages/nrepl-api/supplied_middleware.adoc +++ b/doc/modules/ROOT/pages/nrepl-api/supplied_middleware.adoc @@ -57,6 +57,12 @@ | `inspect-(start/refresh/pop/push/reset/get-path)` | Inspect a Clojure expression. +| `wrap-log` +| 0.30.1 +| No +| `cider/log-add-appender`, `cider/log-add-consumer`, `cider/log-analyze-stacktrace`, `cider/log-clear-appender`, `cider/log-exceptions`, `cider/log-format-event`, `cider/log-frameworks`, `cider/log-inspect-event`, `cider/log-levels`, `cider/log-loggers`, `cider/log-remove-appender`, `cider/log-remove-consumer`, `cider/log-search`, `cider/log-update-appender`, `cider/log-update-consumer`, `cider/log-threads` +| Capture, debug, inspect and view log events emitted by Java logging frameworks. + | `wrap-macroexpand` | - | Yes diff --git a/doc/modules/ROOT/pages/usage.adoc b/doc/modules/ROOT/pages/usage.adoc index 89fba647..9661fec9 100644 --- a/doc/modules/ROOT/pages/usage.adoc +++ b/doc/modules/ROOT/pages/usage.adoc @@ -41,6 +41,7 @@ under `:repl-options`. cider.nrepl/wrap-format cider.nrepl/wrap-info cider.nrepl/wrap-inspect + cider.nrepl/wrap-log cider.nrepl/wrap-macroexpand cider.nrepl/wrap-ns cider.nrepl/wrap-spec @@ -153,6 +154,7 @@ That's how CIDER's nREPL handler is created: cider.nrepl/wrap-format cider.nrepl/wrap-info cider.nrepl/wrap-inspect + cider.nrepl/wrap-log cider.nrepl/wrap-macroexpand cider.nrepl/wrap-ns cider.nrepl/wrap-out diff --git a/project.clj b/project.clj index f0c1395d..1657dfc3 100644 --- a/project.clj +++ b/project.clj @@ -18,7 +18,8 @@ ^:inline-dep [cljfmt "0.9.2" :exclusions [org.clojure/clojurescript]] ^:inline-dep [org.clojure/tools.namespace "1.3.0"] ^:inline-dep [org.clojure/tools.trace "0.7.11"] - ^:inline-dep [org.clojure/tools.reader "1.3.6"]] + ^:inline-dep [org.clojure/tools.reader "1.3.6"] + [mx.cider/logjam "0.1.1"]] :exclusions [org.clojure/clojure] ; see Clojure version matrix in profiles below :pedantic? ~(if (System/getenv "CI") @@ -102,9 +103,13 @@ :test {:global-vars {*assert* true} :source-paths ["test/src"] :java-source-paths ["test/java"] + :jvm-opts ["-Djava.util.logging.config.file=test/resources/logging.properties"] :resource-paths ["test/resources"] :dependencies [[boot/base "2.8.3"] [boot/core "2.8.3"] + ;; 1.3.7 and 1.4.7 are working, but we need 1.3.7 for JDK8 + [ch.qos.logback/logback-classic "1.3.7"] + [org.clojure/test.check "1.1.1"] [org.apache.httpcomponents/httpclient "4.5.13" :exclusions [commons-logging]] [leiningen-core "2.9.10" :exclusions [org.clojure/clojure commons-codec diff --git a/src/cider/nrepl.clj b/src/cider/nrepl.clj index 5d330569..0063dc66 100644 --- a/src/cider/nrepl.clj +++ b/src/cider/nrepl.clj @@ -284,6 +284,136 @@ Depending on the type of the return value of the evaluation this middleware may "var-name" "The var name"} :returns {"status" "\"done\""}}}})) +(def-wrapper wrap-log cider.nrepl.middleware.log/handle-log + {:doc "Middleware that captures log events and makes them inspect-able." + :requires #{#'session #'wrap-print} + :handles + {"cider/log-add-appender" + {:doc "Add an appender to a log framework." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "filters" "A map from filter name to filter condition." + "size" "The number of events the appender keeps in memory." + "threshold" "The threshold in percent used to cleanup events."} + :optional {"logger" "The name of the logger to attach to."} + :returns {"status" "done" + "cider/log-add-appender" "The appender that was added."}} + + "cider/log-add-consumer" + {:doc "Add a consumer to an appender of a log framework." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "filters" "A map from filter name to filter condition."} + :returns {"status" "done" + "cider/log-add-consumer" "The consumer that was added."}} + + "cider/log-analyze-stacktrace" + {:doc "Analyze the stacktrace of a log event." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "event" "The id of the event to inspect."} + :returns {"status" "done"}} + + "cider/log-clear-appender" + {:doc "Clear all events of a log appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-clear-appender" "The appender that was cleared."}} + + "cider/log-exceptions" + {:doc "Return the exceptions and their frequencies for the given framework and appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-exceptions" "A map from exception name to event frequency."}} + + "cider/log-frameworks" + {:doc "Return the available log frameworks." + :returns {"status" "done" + "cider/log-frameworks" "A list of log frameworks."}} + + "cider/log-format-event" + {:doc "Format a log event." + :requires {"framework" "The id of the log framework." + "appender" "The name of the log appender." + "event" "The id of the log event."} + :optional wrap-print-optional-arguments + :returns {"status" "done" + "cider/log-format-event" "The formatted log event."}} + + "cider/log-inspect-event" + {:doc "Inspect a log event." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "event" "The id of the event to inspect."} + :returns {"status" "done" + "value" "The inspection result."}} + + "cider/log-levels" + {:doc "Return the log levels and their frequencies for the given framework and appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-levels" "A map from log level to event frequency."}} + + "cider/log-loggers" + {:doc "Return the loggers and their frequencies for the given framework and appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-loggers" "A map from logger name to event frequency."}} + + "cider/log-remove-appender" + {:doc "Remove an appender from a log framework." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-remove-appender" "The removed appender."}} + + "cider/log-remove-consumer" + {:doc "Remove a consumer from the appender of a log framework." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "consumer" "The name of the consumer."} + :returns {"status" "done" + "cider/log-add-consumer" "The removed consumer."}} + + "cider/log-update-appender" + {:doc "Update the appender of a log framework." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "filters" "A map from filter name to filter condition." + "size" "The number of events the appender keeps in memory." + "threshold" "The threshold in percent used to cleanup events."} + :returns {"status" "done" + "cider/log-update-appender" "The updated appender."}} + + "cider/log-update-consumer" + {:doc "Update the consumer of a log appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender." + "consumer" "The name of the consumer." + "filters" "A map from filter name to filter condition."} + :returns {"status" "done" + "cider/log-update-consumer" "The consumer that was updated."}} + + "cider/log-search" + {:doc "Search the log events of an appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :optional {"filters" "A map from filter name to filter condition." + "limit" "Number of log events to return."} + :returns {"status" "done" + "cider/log-search" "The list of log events matching the search."}} + + "cider/log-threads" + {:doc "Return the threads and their frequencies for the given framework and appender." + :requires {"framework" "The id of the log framework." + "appender" "The name of the appender."} + :returns {"status" "done" + "cider/log-threads" "A map from thread name to event frequency."}}}}) + (def-wrapper wrap-macroexpand cider.nrepl.middleware.macroexpand/handle-macroexpand (cljs/requires-piggieback {:doc "Macroexpansion middleware." diff --git a/src/cider/nrepl/middleware.clj b/src/cider/nrepl/middleware.clj index bdd53eb0..293eb097 100644 --- a/src/cider/nrepl/middleware.clj +++ b/src/cider/nrepl/middleware.clj @@ -16,6 +16,7 @@ cider.nrepl/wrap-format cider.nrepl/wrap-info cider.nrepl/wrap-inspect + cider.nrepl/wrap-log cider.nrepl/wrap-macroexpand cider.nrepl/wrap-ns cider.nrepl/wrap-out diff --git a/src/cider/nrepl/middleware/log.clj b/src/cider/nrepl/middleware/log.clj new file mode 100644 index 00000000..1bf12050 --- /dev/null +++ b/src/cider/nrepl/middleware/log.clj @@ -0,0 +1,296 @@ +(ns cider.nrepl.middleware.log + "Capture, debug, inspect and view log events emitted by Java logging frameworks." + {:author "r0man" + :added "0.32.0"} + (:require [cider.nrepl.middleware.inspect :as middleware.inspect] + [cider.nrepl.middleware.util.error-handling :refer [with-safe-transport]] + [haystack.analyzer :as analyzer] + [haystack.parser.clojure.throwable :as throwable] + [logjam.event :as event] + [logjam.framework :as framework] + [nrepl.middleware.print :as print] + [nrepl.misc :refer [response-for]] + [nrepl.transport :as transport] + [orchard.inspect :as orchard.inspect]) + (:import (java.io StringWriter) + (java.util UUID))) + +(defn- select-consumer + "Return the log `consumer` in a Bencode compatible format." + [consumer] + (-> (select-keys consumer [:id :filters]) + (update :id str))) + +(defn- select-appender + "Return the log `appender` in a Bencode compatible format." + [appender] + (-> (select-keys appender [:filters :logger :id :size :threshold]) + (assoc :consumers (map select-consumer (vals (:consumers appender)))))) + +(defn- select-framework + "Return the log `frameowrk` in a Bencode compatible format." + [framework] + (-> (select-keys framework [:id :javadoc-url :name :root-logger :website-url]) + (assoc :appenders (map (comp select-appender deref) + (framework/appenders framework))) + (assoc :levels (map #(select-keys % [:name :category :weight]) (:levels framework))))) + +(defn- select-exception + "Return the `exception` in a Bencode compatible format." + [exception] + (let [exception-map (throwable/Throwable->map exception) + strip-cause #(dissoc % :data :trace)] + (cond-> (strip-cause exception-map) + (seq (:via exception-map)) + (update :via #(map strip-cause %))))) + +(defn- select-event + "Return the log `event` in a Bencode compatible format." + [{:keys [exception id] :as event}] + (cond-> (select-keys event [:exception :level :logger :message :id :thread :timestamp]) + (uuid? id) + (update :id str) + (instance? Throwable exception) + (update :exception select-exception))) + +;; TODO: Double check this! Sometimes inspecting a log event works only after +;; inspecting something else with the Cider inspector. +(defn- inspect-value + "Show `value` in the Cider inspector" + [{:keys [page-size max-atom-length max-coll-size] :as msg} value] + (let [inspector (middleware.inspect/swap-inspector! + msg #(-> (assoc % :page-size (or page-size 32) + :indentation 0 + :max-atom-length max-atom-length + :max-coll-size max-coll-size) + (orchard.inspect/start value)))] + (#'middleware.inspect/inspector-response msg inspector))) + +(defn- framework + "Lookup the framework from the :framework key of the NREPL message." + [{:keys [session framework]}] + (or (get-in (meta session) [::frameworks framework]) + (throw (ex-info "Log framework not found" + {:error :log-framework-not-found + :framework framework})))) + +(defn- filters + "Extract the filters from an NREPL dictinary." + [{:keys [end-time exceptions level loggers pattern start-time threads]}] + (cond-> {} + (nat-int? end-time) + (assoc :end-time end-time) + (and (seq exceptions) (every? string? exceptions)) + (assoc :exceptions exceptions) + (or (string? level) (keyword? level)) + (assoc :level (keyword level)) + (and (seq loggers) (every? string? loggers)) + (assoc :loggers loggers) + (string? pattern) + (assoc :pattern pattern) + (nat-int? start-time) + (assoc :start-time start-time) + (and (seq threads) (every? string? threads)) + (assoc :threads threads))) + +(defn- appender + "Make an appender map from the :appender, :filters, :size + and :threshold keys of the NREPL message." + [{:keys [appender logger size threshold] :as msg}] + (when (string? appender) + (cond-> {:id appender} + (map? (:filters msg)) + (assoc :filters (filters (:filters msg))) + (string? logger) + (assoc :logger logger) + (pos-int? size) + (assoc :size size) + (nat-int? threshold) + (assoc :threshold threshold)))) + +(defn- consumer + "Make a consumer map from the :consumer and :filters keys of the NREPL message." + [{:keys [consumer] :as msg}] + (when (string? consumer) + (cond-> {:id consumer} + (map? (:filters msg)) + (assoc :filters (filters (:filters msg)))))) + +(defn- event + "Lookup the log event from the :framework, :appender and :event + keys of the NREPL `msg`." + [{:keys [event] :as msg}] + (or (framework/event (framework msg) (appender msg) (UUID/fromString event)) + (throw (ex-info "Log event not found" + {:error :log-event-not-found + :framework (:framework msg) + :appender (:appender msg) + :event event})))) + +(defn swap-framework! + "Swap the framework bound in the session by applying `f` with `args`." + [msg f & args] + (if-let [framework (framework msg)] + (-> (:session msg) + (alter-meta! update-in [::frameworks (:id framework)] #(apply f % args)) + (get-in [::frameworks (:id framework)])) + (throw (ex-info "Log framework not found" + {:type :log-framework-not-found + :framework (:framework msg)})))) + +(defn add-appender-reply + "Add an appender to a log framework." + [msg] + (let [appender (appender msg)] + {:cider/log-add-appender + (-> (swap-framework! msg framework/add-appender appender) + (framework/appender appender) + (deref) + (select-appender))})) + +(defn add-consumer-reply + "Add a consumer to an appender of a log framework." + [{:keys [consumer filters transport] :as msg}] + (let [appender (appender msg) + consumer {:id (or consumer (str (UUID/randomUUID))) + :filters (or filters {}) + :callback (fn [consumer event] + (->> (response-for msg + :cider/log-consumer (str (:id consumer)) + :cider/log-event (select-event event) + :status :cider/log-event) + (transport/send transport)))}] + {:cider/log-add-consumer + (-> (swap-framework! msg framework/add-consumer appender consumer) + (framework/consumer appender consumer) + (select-consumer))})) + +(defn clear-appender-reply + "Clear all events of a log appender." + [msg] + (let [appender (appender msg)] + {:cider/log-clear-appender + (-> (swap-framework! msg framework/clear-appender appender) + (framework/appender appender) + (deref) + (select-appender))})) + +(defn analyze-stacktrace-reply + "Show the stacktrace of a log event in the debugger." + [{:keys [transport ::print/print-fn] :as msg}] + (let [event (event msg)] + (if-let [exception (:exception event)] + (do (doseq [cause (analyzer/analyze exception print-fn)] + (transport/send transport (response-for msg cause))) + (transport/send transport (response-for msg :status :done))) + (transport/send transport (response-for msg :status :no-error))))) + +(defn exceptions-reply + "Return the exceptions and their frequencies for the given framework and appender." + [msg] + {:cider/log-exceptions (->> (framework/events (framework msg) (appender msg)) + (event/exception-frequencies))}) + +(defn frameworks-reply + "Return the available log frameworks." + [{:keys [session]}] + {:cider/log-frameworks (->> (meta session) + ::frameworks vals + (map select-framework))}) + +(defn format-event-reply + "Format a log event." + [{:keys [::print/print-fn] :as msg}] + (let [event (event msg) + writer (StringWriter.)] + (print-fn event writer) + {:cider/log-format-event (str writer)})) + +(defn inspect-event-reply + "Inspect a log event." + [msg] + (inspect-value msg (event msg))) + +(defn levels-reply + "Return the log levels and their frequencies for the given framework and appender." + [msg] + {:cider/log-levels (->> (framework/events (framework msg) (appender msg)) + (event/level-frequencies))}) + +(defn loggers-reply + "Return the loggers and their frequencies for the given framework and appender." + [msg] + {:cider/log-loggers (->> (framework/events (framework msg) (appender msg)) + (event/logger-frequencies))}) + +(defn remove-appender-reply + "Remove an appender from a log framework." + [msg] + (let [appender (appender msg)] + (swap-framework! msg framework/remove-appender appender) + {:cider/log-remove-appender {:id (str (:id appender))}})) + +(defn remove-consumer-reply + "Remove a consumer from the appender of a log framework." + [msg] + (let [appender (appender msg) + consumer (consumer msg)] + (swap-framework! msg framework/remove-consumer appender consumer) + {:cider/log-remove-consumer (select-consumer consumer)})) + +(defn update-appender-reply + "Update the appender of a log framework." + [msg] + (let [appender (appender msg)] + {:cider/log-update-appender + (-> (swap-framework! msg framework/update-appender appender) + (framework/appender appender) + (deref) + (select-appender))})) + +(defn update-consumer-reply + "Update the consumer of a log appender." + [msg] + (let [appender (appender msg) + consumer (consumer msg)] + {:cider/log-update-consumer + (-> (swap-framework! msg framework/update-consumer appender consumer) + (framework/consumer appender consumer) + (select-consumer))})) + +(defn search-reply + "Search the log events of an appender." + [msg] + {:cider/log-search + (->> (select-keys msg [:filters :limit :offset]) + (framework/search-events (framework msg) (appender msg)) + (map select-event))}) + +(defn threads-reply + "Return the threads and their frequencies for the given framework and appender." + [msg] + {:cider/log-threads (->> (framework/events (framework msg) (appender msg)) + (event/thread-frequencies))}) + +(defn handle-log + "Handle NREPL log operations." + [handler {:keys [session] :as msg}] + (when-not (contains? (meta session) ::frameworks) + (alter-meta! session assoc ::frameworks (framework/resolve-frameworks))) + (with-safe-transport handler msg + "cider/log-add-appender" add-appender-reply + "cider/log-add-consumer" add-consumer-reply + "cider/log-analyze-stacktrace" analyze-stacktrace-reply + "cider/log-clear-appender" clear-appender-reply + "cider/log-exceptions" exceptions-reply + "cider/log-format-event" format-event-reply + "cider/log-frameworks" frameworks-reply + "cider/log-inspect-event" inspect-event-reply + "cider/log-levels" levels-reply + "cider/log-loggers" loggers-reply + "cider/log-remove-appender" remove-appender-reply + "cider/log-remove-consumer" remove-consumer-reply + "cider/log-search" search-reply + "cider/log-update-appender" update-appender-reply + "cider/log-update-consumer" update-consumer-reply + "cider/log-threads" threads-reply)) diff --git a/test/clj/cider/nrepl/middleware/log_test.clj b/test/clj/cider/nrepl/middleware/log_test.clj new file mode 100644 index 00000000..7b510b43 --- /dev/null +++ b/test/clj/cider/nrepl/middleware/log_test.clj @@ -0,0 +1,441 @@ +(ns cider.nrepl.middleware.log-test + (:require [cider.nrepl.test-session :as session] + [clojure.set :as set] + [clojure.test :refer [deftest is testing use-fixtures]] + [clojure.test.check.generators :as gen] + [logjam.framework :as framework])) + +(use-fixtures :each session/session-fixture) + +(def appender + {:id "my-appender"}) + +(defn frameworks [] + (vals (framework/resolve-frameworks))) + +(defn- find-framework [frameworks framework] + (some #(and (= (name (:id framework)) (:id %)) %) frameworks)) + +(defn- exception-gen [] + (->> (gen/tuple gen/string-alphanumeric + (gen/map gen/keyword gen/any-printable-equatable)) + (gen/fmap (fn [[msg data]] (ex-info msg data))))) + +(defn event-gen [framework] + (->> (gen/tuple (gen/hash-map + :arguments (gen/vector gen/any-printable-equatable) + :logger gen/string-ascii + :message gen/string-ascii + :thread gen/string-ascii + :timestamp gen/nat) + (gen/elements (:levels framework)) + (exception-gen)) + (gen/fmap (fn [[event level exception]] + (cond-> (assoc event :level (:name level)) + (= :error (:category level)) + (assoc :exception exception)))))) + +(defn- uuid-str? [s] + (try (java.util.UUID/fromString s) + (catch Exception _))) + +(defn- add-appender [framework appender & [opts]] + (let [{:keys [status cider/log-add-appender] :as response} + (session/message (merge {:op "cider/log-add-appender" + :framework (:id framework) + :appender (:id appender)} + opts))] + (assert (= #{"done"} status) response) + log-add-appender)) + +(defn- add-consumer [framework appender & [opts]] + (let [{:keys [status cider/log-add-consumer] :as response} + (session/message (merge {:op "cider/log-add-consumer" + :framework (:id framework) + :appender (:id appender)} + opts))] + (assert (= #{"done"} status) response) + log-add-consumer)) + +(defn- remove-appender [framework appender] + (let [{:keys [status cider/log-remove-appender] :as response} + (session/message {:op "cider/log-remove-appender" + :framework (:id framework) + :appender (:id appender)})] + (assert (= #{"done"} status) response) + log-remove-appender)) + +(defn- search-events [framework appender & [opts]] + (let [{:keys [status cider/log-search] :as response} + (session/message (merge {:op "cider/log-search" + :framework (:id framework) + :appender (:id appender)} + opts))] + (assert (= #{"done"} status) response) + log-search)) + +(defmacro with-each-framework + "Evaluate `body` for each `framework` bound to `framework-sym`." + [[framework-sym frameworks] & body] + `(doseq [framework# ~frameworks :let [~framework-sym framework#]] + (testing (format "Log framework %s" (:name framework#)) + ~@body))) + +(defmacro with-appender + "Add an appender for `framework`, evaluate `body` and remove the appender." + [[framework appender options] & body] + `(let [framework# ~framework, appender# ~appender] + (add-appender framework# appender# ~options) + (try ~@body (finally (remove-appender framework# appender#))))) + +(deftest test-add-appender + (with-each-framework [framework (frameworks)] + (let [options {:filters {} :size 10 :threshold 10} + appender' (add-appender framework appender options)] + (is (= [] (:consumers appender'))) + (is (= (:filters options) (:filters appender'))) + (is (= (:id appender) (:id appender'))) + (is (= (:root-logger framework) (:logger appender'))) + (is (= (:size options) (:size appender'))) + (is (= (:threshold options) (:threshold appender')))) + (remove-appender framework appender))) + +(deftest test-add-consumer + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [options {:filters {:level :INFO}} + consumer (add-consumer framework appender options)] + (is (uuid-str? (:id consumer))) + (is (= {:level "INFO"} (:filters consumer)))) + (framework/log framework {:message "a-1"}) + ;; TODO: How to receive the async log event? + ))) + +(deftest test-analyze-stacktrace + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1" :exception (ex-info "BOOM" {:some (Object.)})}) + (let [events (search-events framework appender {})] + (is (= 1 (count events))) + (let [event (first events)] + (is (uuid-str? (:id event))) + (is (string? (:level event))) + (is (string? (:logger event))) + (is (= "a-1" (:message event))) + (is (int? (:timestamp event))) + (let [response (session/message {:op "cider/log-analyze-stacktrace" + :framework (:id framework) + :appender (:id appender) + :event (:id event)})] + (is (= #{"done"} (:status response))) + (is (every? #(set/subset? #{:type :flags} (set (keys %))) + (:stacktrace response))))))))) + +(deftest test-clear + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (let [response (session/message {:op "cider/log-clear-appender" + :framework (:id framework) + :appender (:id appender)})] + (is (= #{"done"} (:status response))) + (is (= {:consumers [] + :filters {} + :id (:id appender) + :logger (:root-logger framework) + :size 100000 + :threshold 10} + (:cider/log-clear-appender response))))))) + +(deftest test-exceptions + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1" :exception (IllegalArgumentException. "BOOM")}) + (framework/log framework {:message "b-1" :exception (IllegalStateException. "BOOM")}) + (framework/log framework {:message "b-2" :exception (IllegalStateException. "BOOM")}) + (let [response (session/message {:op "cider/log-exceptions" + :framework (:id framework) + :appender (:id appender)})] + (is (= #{"done"} (:status response))) + (is (= {:java.lang.IllegalArgumentException 1 + :java.lang.IllegalStateException 2} + (:cider/log-exceptions response))))))) + +(deftest test-frameworks + (let [{:keys [cider/log-frameworks status]} (session/message {:op "cider/log-frameworks"})] + (is (= #{"done"} status)) + (is (= ["Logback" "Java Util Logging"] (map :name log-frameworks))) + (with-each-framework [framework (frameworks)] + (let [framework' (find-framework log-frameworks framework)] + (is (= [] (:appenders framework'))) + (is (= (:id framework) (name (:id framework')))) + (is (= (:javadoc-url framework) (:javadoc-url framework'))) + (is (= (:name framework) (:name framework'))) + (is (= (map (fn [level] + {:name (name (:name level)) + :category (name (:category level)) + :weight (:weight level)}) + (:levels framework)) + (:levels framework'))) + (is (= (:website-url framework) (:website-url framework'))) + (is (string? (:root-logger framework'))))))) + +(deftest test-frameworks-add-appender + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [{:keys [cider/log-frameworks status]} (session/message {:op "cider/log-frameworks"})] + (is (= #{"done"} status)) + (let [framework' (find-framework log-frameworks framework)] + (is (= [{:consumers [] + :filters {} + :id (:id appender) + :logger (:root-logger framework) + :size 100000 + :threshold 10}] + (:appenders framework'))) + (is (= (:id framework) (name (:id framework')))) + (is (= (:javadoc-url framework) (:javadoc-url framework'))) + (is (= (:name framework) (:name framework'))) + (is (= (:website-url framework) (:website-url framework'))) + (is (string? (:root-logger framework')))))))) + +(deftest test-format-event + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (add-appender framework appender) + (framework/log framework {:message "a-1"}) + (framework/log framework {:message "a-2"}) + (doseq [event (:cider/log-search + (session/message + {:op "cider/log-search" + :framework (:id framework) + :appender (:id appender)}))] + (let [response (session/message {:op "cider/log-format-event" + :framework (:id framework) + :appender (:id appender) + :event (:id event)})] + (is (= #{"done"} (:status response))) + (is (re-matches (re-pattern (str ".*" (:message event) ".*")) + (:cider/log-format-event response)))))))) + +(deftest test-inspect + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (add-appender framework appender) + (framework/log framework {:message "a-1"}) + (framework/log framework {:message "a-2"}) + (doseq [event (:cider/log-search + (session/message + {:op "cider/log-search" + :framework (:id framework) + :appender (:id appender)}))] + (let [response (session/message {:op "cider/log-inspect-event" + :framework (:id framework) + :appender (:id appender) + :event (:id event)})] + (is (= #{"done"} (:status response))) + (is (re-matches (re-pattern (format "(?s).*%s.*" (:id event))) + (first (:value response))))))))) + +(deftest test-levels + (with-each-framework [framework (frameworks)] + (let [levels (map :name (reverse (:levels framework)))] + (with-appender [framework appender] + (doseq [level levels] + (framework/log framework {:level level :message (name level)})) + (let [response (session/message {:op "cider/log-levels" + :framework (:id framework) + :appender (:id appender)})] + (is (= #{"done"} (:status response))) + (is (= (into {} (map #(vector % 1) levels)) + (:cider/log-levels response)))))))) + +(deftest test-loggers + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:logger "LOGGER-A" :message "a-1"}) + (framework/log framework {:logger "LOGGER-B" :message "b-1"}) + (framework/log framework {:logger "LOGGER-B" :message "b-2"}) + (let [response (session/message {:op "cider/log-loggers" + :framework (:id framework) + :appender (:id appender)})] + (is (= #{"done"} (:status response))) + (is (= {:LOGGER-A 1 :LOGGER-B 2} (:cider/log-loggers response))))))) + +(deftest test-search + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (framework/log framework {:message "a-2"}) + (framework/log framework {:message "a-3"}) + (let [events (search-events framework appender {})] + (is (= 3 (count events))) + (is (= ["a-3" "a-2" "a-1"] (map :message events))))))) + +(deftest test-search-by-level + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [[level-1 level-2 level-3] (map :name (:levels framework))] + (framework/log framework {:level level-1 :message "a-1"}) + (framework/log framework {:level level-2 :message "a-2"}) + (framework/log framework {:level level-3 :message "a-3"}) + (is (= 3 (count (search-events framework appender {:filters {:level level-1}})))) + (is (= 2 (count (search-events framework appender {:filters {:level level-2}})))) + (is (= 1 (count (search-events framework appender {:filters {:level level-3}})))))))) + +(deftest test-search-by-exception + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (framework/log framework {:message "a-2" :exception (IllegalArgumentException. "BOOM")}) + (framework/log framework {:message "a-3" :exception (IllegalStateException. "BOOM")}) + (let [options {:filters {:exceptions ["java.lang.IllegalStateException"]}} + events (search-events framework appender options)] + (is (= 1 (count events))) + (let [event (first events)] + (is (uuid-str? (:id event))) + (is (string? (:level event))) + (is (string? (:logger event))) + (is (= "a-3" (:message event))) + (is (int? (:timestamp event)))))))) + +(deftest test-search-by-pattern + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (framework/log framework {:message "a-2"}) + (framework/log framework {:message "a-3"}) + (let [events (search-events framework appender {:filters {:pattern "a-3"}})] + (is (= 1 (count events))) + (let [event (first events)] + (is (uuid-str? (:id event))) + (is (= "INFO" (:level event))) + (is (string? (:logger event))) + (is (= "a-3" (:message event))) + (is (int? (:timestamp event)))))))) + +(deftest test-search-by-start-and-end-time + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (Thread/sleep 100) + (framework/log framework {:message "a-2"}) + (Thread/sleep 100) + (framework/log framework {:message "a-3"}) + (let [[event-3 event-2 event-1] (search-events framework appender {})] + (let [options {:filters {:start-time (inc (:timestamp event-1)) + :end-time (dec (:timestamp event-3))}} + events (search-events framework appender options)] + (is (= 1 (count events))) + (let [event (first events)] + (is (= (:id event-2) (:id event))) + (is (= "INFO" (:level event))) + (is (string? (:logger event))) + (is (= "a-2" (:message event))) + (is (int? (:timestamp event))))))))) + +(deftest test-threads + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (framework/log framework {:message "a-1"}) + (let [response (session/message + {:op "cider/log-threads" + :framework (:id framework) + :appender (:id appender)})] + (is (= #{"done"} (:status response))) + (let [threads (:cider/log-threads response)] + (is (every? keyword? (keys threads))) + (is (every? pos-int? (vals threads)))))))) + +(deftest test-remove-appender + (with-each-framework [framework (frameworks)] + (testing "remove unregistered appender" + (let [response (session/message + {:op "cider/log-remove-appender" + :framework (:id framework) + :appender "unknown"})] + (is (= #{"cider/log-remove-appender-error" "done"} (:status response))))) + (testing "remove registered appender" + (let [appender (add-appender framework appender) + appender' (remove-appender framework appender)] + (is (= (:id appender) (:id appender'))) + (let [{:keys [log-frameworks status]} (session/message {:op "cider/log-frameworks"})] + (is (= #{"done"} status)) + (is (empty? (:appenders (find-framework log-frameworks framework))))))))) + +(deftest test-remove-consumer + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [consumer (add-consumer framework appender {:filters {:level :INFO}}) + response (session/message + {:op "cider/log-remove-consumer" + :framework (:id framework) + :appender (:id appender) + :consumer (:id consumer)})] + (is (= #{"done"} (:status response))) + (is (= {:id (:id consumer)} + (:cider/log-remove-consumer response))) + (let [{:keys [cider/log-frameworks status]} (session/message {:op "cider/log-frameworks"})] + (is (= #{"done"} status)) + (is (= [{:consumers [] + :filters {} + :id (:id appender) + :logger (:root-logger framework) + :size 100000 + :threshold 10}] + (:appenders (find-framework log-frameworks framework))))))))) + +(deftest test-update-appender + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [response (session/message + {:op "cider/log-update-appender" + :appender (:id appender) + :filters {:pattern "A.*"} + :framework (:id framework) + :size 2 + :threshold 0})] + (is (= #{"done"} (:status response))) + (let [appender (:cider/log-update-appender response)] + (is (= {:pattern "A.*"} (:filters appender))) + (is (= 2 (:size appender))) + (is (= 0 (:threshold appender))) + (framework/log framework {:message "A1"}) + (framework/log framework {:message "A2"}) + (framework/log framework {:message "A3"}) + (framework/log framework {:message "A4"}) + (framework/log framework {:message "B1"}) + (let [events (:cider/log-search + (session/message + {:op "cider/log-search" + :framework (:id framework) + :appender (:id appender)}))] + (is (= ["A4" "A3"] (map :message events))))))))) + +(deftest test-update-consumer + (with-each-framework [framework (frameworks)] + (with-appender [framework appender] + (let [consumer (add-consumer framework appender {:filters {:level :INFO}}) + response (session/message + {:op "cider/log-update-consumer" + :framework (:id framework) + :appender (:id appender) + :consumer (:id consumer) + :filters {:level :DEBUG}})] + (is (= #{"done"} (:status response))) + (is (= {:id (:id consumer) + :filters {:level "DEBUG"}} + (:cider/log-update-consumer response))) + (framework/log framework {:message "B1" :level :DEBUG}))))) + +(defn log-something [framework & [^long n ^long sleep]] + (doseq [event (gen/sample (event-gen framework) (or n 1))] + (framework/log framework event) + (Thread/sleep (or sleep 10)))) + +(deftest test-log-something + (doseq [framework (frameworks)] + (is (nil? (log-something framework 10))))) + +(comment + (future (log-something (first (frameworks)) 1000))) diff --git a/test/resources/logback-test.xml b/test/resources/logback-test.xml new file mode 100644 index 00000000..94f549f0 --- /dev/null +++ b/test/resources/logback-test.xml @@ -0,0 +1,16 @@ + + + + + %d{yyyy-MM-dd}T%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n + + + OFF + + + + + + + + diff --git a/test/resources/logging.properties b/test/resources/logging.properties new file mode 100644 index 00000000..b51cf8e9 --- /dev/null +++ b/test/resources/logging.properties @@ -0,0 +1,59 @@ +############################################################ +# Default Logging Configuration File +# +# You can use a different file by specifying a filename +# with the java.util.logging.config.file system property. +# For example java -Djava.util.logging.config.file=myfile +############################################################ + +############################################################ +# Global properties +############################################################ + +# "handlers" specifies a comma separated list of log Handler +# classes. These handlers will be installed during VM startup. +# Note that these classes must be on the system classpath. +# By default we only configure a ConsoleHandler, which will only +# show messages at the INFO and above levels. +handlers=java.util.logging.FileHandler + +# To also add the FileHandler, use the following line instead. +#handlers= java.util.logging.FileHandler, java.util.logging.ConsoleHandler + +# Default global logging level. +# This specifies which kinds of events are logged across +# all loggers. For any given facility this global level +# can be overriden by a facility specific level +# Note that the ConsoleHandler also has a separate level +# setting to limit messages printed to the console. +.level= ALL + +############################################################ +# Handler specific properties. +# Describes specific configuration info for Handlers. +############################################################ + +# default file output is in user's home directory. +java.util.logging.FileHandler.pattern = %h/java%u.log +java.util.logging.FileHandler.limit = 50000 +java.util.logging.FileHandler.count = 1 +java.util.logging.FileHandler.formatter = java.util.logging.XMLFormatter + +# Limit the message that are printed on the console to INFO and above. +java.util.logging.ConsoleHandler.level = INFO +java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter + +# Example to customize the SimpleFormatter output format +# to print one-line log message like this: +# : [] +# +# java.util.logging.SimpleFormatter.format=%4$s: %5$s [%1$tc]%n + +############################################################ +# Facility specific properties. +# Provides extra control for each logger. +############################################################ + +# For example, set the com.xyz.foo logger to only log SEVERE +# messages: +com.xyz.foo.level = SEVERE