From 1839397ebc8424306eb1c99fd0670be82c78bcaa Mon Sep 17 00:00:00 2001 From: Andrey Antukh Date: Thu, 23 Dec 2021 18:36:58 +0100 Subject: [PATCH] :sparkles: Minor enhacements on log processing. --- .clj-kondo/config.edn | 3 +- .clj-kondo/hooks/export.clj | 2 - backend/src/app/http.clj | 17 ++----- backend/src/app/http/errors.clj | 73 ++++++++++-------------------- backend/src/app/http/session.clj | 1 - backend/src/app/worker.clj | 9 +--- common/src/app/common/data.cljc | 2 +- common/src/app/common/logging.cljc | 66 +++++++++++++++++++-------- common/src/app/common/spec.cljc | 9 +--- frontend/src/app/main/errors.cljs | 9 +--- 10 files changed, 83 insertions(+), 108 deletions(-) diff --git a/.clj-kondo/config.edn b/.clj-kondo/config.edn index d1e91f24b..4ba5b0442 100644 --- a/.clj-kondo/config.edn +++ b/.clj-kondo/config.edn @@ -3,7 +3,8 @@ rumext.alpha/defc clojure.core/defn rumext.alpha/fnc clojure.core/fn app.common.data/export clojure.core/def - app.db/with-atomic clojure.core/with-open} + app.db/with-atomic clojure.core/with-open + app.common.logging/with-context clojure.core/do} :hooks {:analyze-call diff --git a/.clj-kondo/hooks/export.clj b/.clj-kondo/hooks/export.clj index f66d02783..16ab4e76a 100644 --- a/.clj-kondo/hooks/export.clj +++ b/.clj-kondo/hooks/export.clj @@ -74,5 +74,3 @@ ;; (prn "==============" rtype (into {} ?meta)) ;; (prn (api/sexpr result)) {:node result})) - - diff --git a/backend/src/app/http.clj b/backend/src/app/http.clj index 0dc98852b..3d8185be1 100644 --- a/backend/src/app/http.clj +++ b/backend/src/app/http.clj @@ -90,20 +90,9 @@ (try (handler request) (catch Throwable e - (try - (let [cdata (errors/get-error-context request e)] - (l/update-thread-context! cdata) - (l/error :hint "unhandled exception" - :message (ex-message e) - :error-id (str (:id cdata)) - :cause e)) - {:status 500 :body "internal server error"} - (catch Throwable e - (l/error :hint "unhandled exception" - :message (ex-message e) - :cause e) - {:status 500 :body "internal server error"}))))))) - + (l/with-context (errors/get-error-context request e) + (l/error :hint (ex-message e) :cause e) + {:status 500 :body "internal server error"})))))) ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; ;; Http Main Handler (Router) diff --git a/backend/src/app/http/errors.clj b/backend/src/app/http/errors.clj index ec489054e..531f59727 100644 --- a/backend/src/app/http/errors.clj +++ b/backend/src/app/http/errors.clj @@ -7,7 +7,6 @@ (ns app.http.errors "A errors handling for the http server." (:require - [app.common.data :as d] [app.common.exceptions :as ex] [app.common.logging :as l] [app.common.uuid :as uuid] @@ -20,36 +19,18 @@ (get headers "x-real-ip") (get request :remote-addr))) - -(defn- simple-prune - ([s] (simple-prune s (* 1024 1024))) - ([s max-length] - (if (> (count s) max-length) - (str (subs s 0 max-length) " [...]") - s))) - -(defn- stringify-data - [data] - (binding [clojure.pprint/*print-right-margin* 200] - (let [result (with-out-str (clojure.pprint/pprint data))] - (simple-prune result (* 1024 1024))))) - (defn get-error-context [request error] (let [data (ex-data error)] - (d/without-nils - (merge - {:id (str (uuid/next)) - :path (str (:uri request)) - :method (name (:request-method request)) - :hint (or (:hint data) (ex-message error)) - :params (stringify-data (:params request)) - :data (stringify-data (dissoc data :explain)) - :ip-addr (parse-client-ip request) - :explain (str/prune (:explain data) (* 1024 1024) "[...]")} - - (when-let [id (:profile-id request)] - {:profile-id id}) + (merge + {:id (uuid/next) + :path (:uri request) + :method (:request-method request) + :hint (or (:hint data) (ex-message error)) + :params (l/stringify-data (:params request)) + :data (l/stringify-data (dissoc data :explain)) + :ip-addr (parse-client-ip request) + :profile-id (:profile-id request)} (let [headers (:headers request)] {:user-agent (get headers "user-agent") @@ -57,7 +38,7 @@ (when (map? data) {:error-type (:type data) - :error-code (:code data)}))))) + :error-code (:code data)})))) (defmulti handle-exception (fn [err & _rest] @@ -89,13 +70,9 @@ (defmethod handle-exception :assertion [error request] - (let [edata (ex-data error) - cdata (get-error-context request error)] - (l/update-thread-context! cdata) - (l/error :hint "internal error: assertion" - :error-id (str (:id cdata)) - :cause error) - + (let [edata (ex-data error)] + (l/with-context (get-error-context request error) + (l/error :hint "internal error: assertion" :cause error)) {:status 500 :body {:type :server-error :code :assertion @@ -116,12 +93,10 @@ (if (and (ex/exception? (:rollback edata)) (ex/exception? (:handling edata))) (handle-exception (:handling edata) request) - (let [cdata (get-error-context request error)] - (l/update-thread-context! cdata) - (l/error :hint "internal error" - :error-message (ex-message error) - :error-id (str (:id cdata)) - :cause error) + (do + (l/with-context (get-error-context request error) + (l/error :hint (ex-message error) :cause error)) + {:status 500 :body {:type :server-error :code :unexpected @@ -130,15 +105,13 @@ (defmethod handle-exception org.postgresql.util.PSQLException [error request] - (let [cdata (get-error-context request error) - state (.getSQLState ^java.sql.SQLException error)] + (let [state (.getSQLState ^java.sql.SQLException error)] - (l/update-thread-context! cdata) - (l/error :hint "psql exception" - :error-message (ex-message error) - :error-id (str (:id cdata)) - :sql-state state - :cause error) + (l/with-context (get-error-context request error) + (l/error :hint "psql exception" + :error-message (ex-message error) + :state state + :cause error)) (cond (= state "57014") diff --git a/backend/src/app/http/session.clj b/backend/src/app/http/session.clj index db7207d15..288896140 100644 --- a/backend/src/app/http/session.clj +++ b/backend/src/app/http/session.clj @@ -73,7 +73,6 @@ (if-let [{:keys [id profile-id] :as session} (retrieve-from-request cfg request)] (do (a/>!! (::events-ch cfg) id) - (l/update-thread-context! {:profile-id profile-id}) (handler (assoc request :profile-id profile-id))) (handler request)))) diff --git a/backend/src/app/worker.clj b/backend/src/app/worker.clj index 49370e164..6d979da8c 100644 --- a/backend/src/app/worker.clj +++ b/backend/src/app/worker.clj @@ -266,13 +266,8 @@ (= ::noop (:strategy edata)) (assoc :inc-by 0)) - - (let [cdata (get-error-context error item)] - (l/update-thread-context! cdata) - (l/error :cause error - :hint "unhandled exception on task" - :id (:id cdata)) - + (l/with-context (get-error-context error item) + (l/error :cause error :hint "unhandled exception on task") (if (>= (:retry-num item) (:max-retries item)) {:status :failed :task item :error error} {:status :retry :task item :error error}))))) diff --git a/common/src/app/common/data.cljc b/common/src/app/common/data.cljc index a39c6c38a..d43d9eb30 100644 --- a/common/src/app/common/data.cljc +++ b/common/src/app/common/data.cljc @@ -6,7 +6,7 @@ (ns app.common.data "Data manipulation and query helper functions." - (:refer-clojure :exclude [read-string hash-map merge name]) + (:refer-clojure :exclude [read-string hash-map merge name parse-double]) #?(:cljs (:require-macros [app.common.data])) (:require diff --git a/common/src/app/common/logging.cljc b/common/src/app/common/logging.cljc index a861bcc27..29116136c 100644 --- a/common/src/app/common/logging.cljc +++ b/common/src/app/common/logging.cljc @@ -17,9 +17,12 @@ org.apache.logging.log4j.LogManager org.apache.logging.log4j.Logger org.apache.logging.log4j.ThreadContext + org.apache.logging.log4j.CloseableThreadContext org.apache.logging.log4j.message.MapMessage org.apache.logging.log4j.spi.LoggerContext))) +#?(:clj (set! *warn-on-reflection* true)) + #?(:clj (defn build-map-message [m] @@ -37,14 +40,13 @@ (defn get-logger [lname] #?(:clj (.getLogger ^LoggerContext logger-context ^String lname) - :cljs - (glog/getLogger - (cond - (string? lname) lname - (= lname :root) "" - (simple-ident? lname) (name lname) - (qualified-ident? lname) (str (namespace lname) "." (name lname)) - :else (str lname))))) + :cljs (glog/getLogger + (cond + (string? lname) lname + (= lname :root) "" + (simple-ident? lname) (name lname) + (qualified-ident? lname) (str (namespace lname) "." (name lname)) + :else (str lname))))) (defn get-level [level] @@ -151,20 +153,48 @@ ;; CLJ Specific ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; +(defn- simple-prune + ([s] (simple-prune s (* 1024 1024))) + ([s max-length] + (if (> (count s) max-length) + (str (subs s 0 max-length) " [...]") + s))) + #?(:clj - (defn update-thread-context! + (defn stringify-data + [val] + (cond + (instance? clojure.lang.Named val) + (name val) + + (string? val) + val + + (coll? val) + (binding [clojure.pprint/*print-right-margin* 120] + (-> (with-out-str (pprint val)) + (simple-prune (* 1024 1024 3)))) + + :else + (str val)))) + +#?(:clj + (defn data->context-map + ^java.util.Map [data] - (run! (fn [[key val]] - (ThreadContext/put - (name key) - (cond - (coll? val) - (binding [clojure.pprint/*print-right-margin* 120] - (with-out-str (pprint val))) - (instance? clojure.lang.Named val) (name val) - :else (str val)))) + (into {} + (comp (filter second) + (map (fn [[key val]] + [(stringify-data key) + (stringify-data val)]))) data))) +#?(:clj + (defmacro with-context + [data & body] + `(with-open [instance# (CloseableThreadContext/putAll (data->context-map ~data))] + ~@body))) + ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; ;; CLJS Specific ;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;; diff --git a/common/src/app/common/spec.cljc b/common/src/app/common/spec.cljc index e7614707b..5b46c81b2 100644 --- a/common/src/app/common/spec.cljc +++ b/common/src/app/common/spec.cljc @@ -211,13 +211,11 @@ [spec x message context] (if (s/valid? spec x) x - (let [data (s/explain-data spec x) - explain (with-out-str (s/explain-out data))] + (let [data (s/explain-data spec x)] (ex/raise :type :assertion :code :spec-validation :hint message :data data - :explain explain :context context #?@(:cljs [:stack (.-stack (ex-info message {}))]))))) @@ -253,12 +251,9 @@ [spec data] (let [result (s/conform spec data)] (when (= result ::s/invalid) - (let [data (s/explain-data spec data) - explain (with-out-str - (s/explain-out data))] + (let [data (s/explain-data spec data)] (throw (ex/error :type :validation :code :spec-validation - :explain explain :data data)))) result)) diff --git a/frontend/src/app/main/errors.cljs b/frontend/src/app/main/errors.cljs index ba8ca731b..6514e8332 100644 --- a/frontend/src/app/main/errors.cljs +++ b/frontend/src/app/main/errors.cljs @@ -81,10 +81,7 @@ (js/console.group "Validation Error:") (ex/ignoring (js/console.info - (with-out-str - (pprint (dissoc error :explain)))) - (when-let [explain (:explain error)] - (js/console.error explain))) + (with-out-str (pprint error)))) (js/console.groupEnd "Validation Error:")) @@ -138,8 +135,7 @@ (defmethod ptk/handle-error :server-error [{:keys [data hint] :as error}] (let [hint (or hint (:hint data) (:message data)) - info (with-out-str (pprint (dissoc data :explain))) - expl (:explain data) + info (with-out-str (pprint data)) msg (str "Internal Server Error: " hint)] (ts/schedule @@ -150,7 +146,6 @@ (js/console.group msg) (js/console.info info) - (when expl (js/console.error expl)) (js/console.groupEnd msg))) (defn on-unhandled-error