🐛 Harden browser logging against invalid levels (#11693)

* 🐛 Stop browser logging from crashing on empty levels

Stop level->int crashes from taking down the dashboard when a
nil or unknown level reaches the browser logger. Invalid levels
now warn and are ignored in enabled?, setup! and the console
handler, which renders unknown records with a neutral fallback.

Alias the schema-legal :fatal level to :error in the browser
mappings and validate the JS-exported debug.set_logging, which
previously threw on missing arguments and wrote unreachable
keyword keys into the loggers map.

Closes #11690

AI-assisted-by: muse-spark-1.3-contributor

* 🐛 Guard logger args and strengthen logging tests

Close the residual throw paths next to the empty-level crash:
guard non-string loggers in enabled? and setup!, coerce
set_logging arguments safely, and validate logger keys.

Strengthen the regression tests so the fatal alias cannot
regress silently: enabled-logger filtering, JVM fatal and bogus
cases, setup! skip proof, and invalid-logger cases.

Related to #11690

AI-assisted-by: muse-spark-1.3-contributor

* 🐛 Address low findings from logging review

Validate the logger before the level in console-log-handler,
share a public valid-logger? predicate with debug/set-logging,
and keep warn formatting consistent across boundaries.

Document the fail-soft-FE/strict-BE split on enabled? and the
valid-level? contract on set-level!. Cover safe fallbacks, bad
logger keys, handler logger skips, and loggers-map isolation in
common tests, and add a frontend test for debug/set-logging.

Related to #11690

AI-assisted-by: muse-spark-1.3-contributor
This commit is contained in:
Andrey Antukh 2026-09-30 07:17:02 +02:00 committed by GitHub
parent 94d6f5a25c
commit 0ef35fc52a
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
6 changed files with 249 additions and 34 deletions

View File

@ -104,8 +104,26 @@
100)
(recur (get-parent-logger logger'))))))))))
(def valid-levels
"The set of log levels accepted on every runtime."
#{:trace :debug :info :warn :error :fatal})
(defn valid-level?
"True when `level` is accepted on every runtime."
[level]
(contains? valid-levels level))
(defn valid-logger?
"True when `logger` is a usable logger name."
[logger]
(and (string? logger) (not (str/blank? logger))))
(defn enabled?
"Check if logger has enabled logging for given level."
"Check if logger has enabled logging for given level.
On CLJS, invalid loggers and levels warn and return false so logging
can never crash the app; on CLJ, invalid levels still throw
IllegalArgumentException."
[logger level]
#?(:clj
(let [logger (LoggerFactory/getLogger ^String logger)]
@ -118,13 +136,26 @@
:fatal (and (.isErrorEnabled ^Logger logger) logger)
(throw (IllegalArgumentException. (str "invalid level:" level)))))
:cljs
(>= (level->int level)
(get-logger-level logger))))
(cond
(not (valid-logger? logger))
(do
(js/console.warn "ignoring invalid logger:" (pr-str logger))
false)
(not (valid-level? level))
(do
(js/console.warn "ignoring invalid log level:" (pr-str level) "logger:" (pr-str logger))
false)
:else
(>= (level->int level)
(get-logger-level logger)))))
(defn- level->color
[level]
(case level
:error "#c82829"
:fatal "#c82829"
:warn "#f5871f"
:info "#4271ae"
:debug "#969896"
@ -140,6 +171,7 @@
:info "INF"
:warn "WRN"
:error "ERR"
:fatal "ERR"
(let [hint (str "invalid level provided to `level->name` function: " (pr-str level))]
(throw (ex-info hint {:level level})))))
@ -151,9 +183,26 @@
:info 30
:warn 40
:error 50
:fatal 50
(let [hint (str "invalid level provided to `level->int` function: " (pr-str level))]
(throw (ex-info hint {:level level})))))
#?(:cljs
(defn level->color-safe
"Like `level->color` but falls back to a neutral gray instead of throwing."
[level]
(if (valid-level? level)
(level->color level)
"#969896")))
#?(:cljs
(defn level->name-safe
"Like `level->name` but falls back to \"UNK\" instead of throwing."
[level]
(if (valid-level? level)
(level->name level)
"UNK")))
(defn build-message
[props]
(loop [props (seq props)
@ -284,43 +333,55 @@
(defn console-log-handler
{:no-doc true}
[_ _ _ {:keys [::logger ::props ::level ::cause ::trace ::message]}]
(when (enabled? logger level)
(let [hstyles (str/ffmt "font-weight: 600; color: %" (level->color level))
mstyles (str/ffmt "font-weight: 300; color: %" (level->color level))
ts (ct/format-inst (ct/now) "kk:mm:ss.SSSS")
header (str/concat "%c" (level->name level) " " ts " [" logger "] ")
message (str/concat header "%c" @message)]
;; Invalid levels render with a fallback style instead of being
;; dropped, so a corrupt record stays visible; the warn below keeps
;; it noticeable. The normal `log!` path never reaches here because
;; `enabled?` already drops such records before `emit-log`.
(if-not (valid-logger? logger)
(js/console.warn "ignoring log record with invalid logger:" (pr-str logger))
(when (or (not (valid-level? level))
(enabled? logger level))
(when-not (valid-level? level)
(js/console.warn "invalid level on log record, using fallback rendering:" (pr-str level) "logger:" (pr-str logger)))
(let [hstyles (str/ffmt "font-weight: 600; color: %" (level->color-safe level))
mstyles (str/ffmt "font-weight: 300; color: %" (level->color-safe level))
ts (ct/format-inst (ct/now) "kk:mm:ss.SSSS")
header (str/concat "%c" (level->name-safe level) " " ts " [" logger "] ")
message (str/concat header "%c" @message)]
(js/console.group message hstyles mstyles)
(doseq [[type n v] (get-special-props props)]
(case type
:js (js/console.log n v)
:error (if (ex/error? v)
(js/console.error n (pr-str v))
(js/console.error n v))))
(js/console.group message hstyles mstyles)
(doseq [[type n v] (get-special-props props)]
(case type
:js (js/console.log n v)
:error (if (ex/error? v)
(js/console.error n (pr-str v))
(js/console.error n v))))
(when (ex/exception? cause)
(let [data (ex-data cause)
explain (or (:explain data)
(ex/explain data))]
(when explain
(js/console.log "Explain:")
(js/console.log explain))
(when (ex/exception? cause)
(let [data (ex-data cause)
explain (or (:explain data)
(ex/explain data))]
(when explain
(js/console.log "Explain:")
(js/console.log explain))
(when (and data (not explain))
(js/console.log "Data:")
(js/console.log (pp/pprint-str data)))
(when (and data (not explain))
(js/console.log "Data:")
(js/console.log (pp/pprint-str data)))
(js/console.log @trace #_(.-stack cause))))
(js/console.log @trace #_(.-stack cause))))
(js/console.groupEnd message)))))
(js/console.groupEnd message))))))
#?(:clj (add-watch log-record ::default slf4j-log-handler)
:cljs (add-watch log-record ::default console-log-handler))
(defmacro set-level!
"A CLJS-only macro for set logging level to current (that matches the
current namespace) or user specified logger."
current namespace) or user specified logger.
Callers passing a dynamic level must check `valid-level?` first;
`level->int` throws on anything outside `valid-levels`."
([level]
(when (:ns &env)
`(.set ^js/Map loggers ~(str *ns*) (level->int ~level))))
@ -332,9 +393,16 @@
(defn setup!
[{:as config}]
(run! (fn [[logger level]]
(let [logger (if (keyword? logger) (name logger) logger)
level (level->int level)]
(.set ^js/Map loggers logger level)))
(let [logger (if (keyword? logger) (name logger) logger)]
(cond
(not (valid-logger? logger))
(js/console.warn "ignoring invalid logger in setup!:" (pr-str logger))
(not (valid-level? level))
(js/console.warn "ignoring invalid log level in setup!:" (pr-str level) "logger:" (pr-str logger))
:else
(.set ^js/Map loggers logger (level->int level)))))
config)))
(defmacro raw!

View File

@ -0,0 +1,101 @@
;; This Source Code Form is subject to the terms of the Mozilla Public
;; License, v. 2.0. If a copy of the MPL was not distributed with this
;; file, You can obtain one at http://mozilla.org/MPL/2.0/.
;;
;; Copyright (c) KALEIDOS INC Sucursal en España SL
(ns common-tests.logging-test
(:require
[app.common.logging :as l]
[clojure.test :as t]))
(defn- throws?
[thunk]
#?(:clj (try (thunk) false (catch clojure.lang.ExceptionInfo _ true))
:cljs (try (thunk) false (catch :default _ true))))
(t/deftest level->int-test
(t/is (= 10 (l/level->int :trace)))
(t/is (= 20 (l/level->int :debug)))
(t/is (= 30 (l/level->int :info)))
(t/is (= 40 (l/level->int :warn)))
(t/is (= 50 (l/level->int :error)))
(t/is (= 50 (l/level->int :fatal)))
(t/is (throws? #(l/level->int nil)))
(t/is (throws? #(l/level->int :bogus))))
#?(:cljs
(t/use-fixtures
:each
(fn [f]
(f)
(doseq [k ["logging-test-probe-xyz"
"logging-test-fatal-xyz"
"logging-test-setup-xyz"
"logging-test-bad-xyz"
"logging-test-key-xyz"]]
(.delete l/loggers k)))))
#?(:cljs
(t/deftest browser-boundaries-test
(t/testing "unknown levels never throw and disable logging"
(t/is (false? (l/enabled? "logging-test-probe-xyz" nil)))
(t/is (false? (l/enabled? "logging-test-probe-xyz" :bogus))))
(t/testing "invalid loggers never throw and disable logging"
(t/is (false? (l/enabled? nil :error)))
(t/is (false? (l/enabled? "" :error)))
(t/is (false? (l/enabled? 123 :error))))
(t/testing "unknown logger defaults to disabled"
(t/is (false? (l/enabled? "logging-test-probe-xyz" :fatal)))
(t/is (false? (l/enabled? "logging-test-probe-xyz" :error))))
(t/testing "fatal filters exactly like error when enabled"
(l/setup! {"logging-test-fatal-xyz" :debug})
(t/is (true? (l/enabled? "logging-test-fatal-xyz" :fatal)))
(t/is (= (l/enabled? "logging-test-fatal-xyz" :fatal)
(l/enabled? "logging-test-fatal-xyz" :error)))
(l/setup! {"logging-test-fatal-xyz" :error})
(t/is (true? (l/enabled? "logging-test-fatal-xyz" :fatal)))
(t/is (false? (l/enabled? "logging-test-fatal-xyz" :debug)))
(t/is (false? (l/enabled? "logging-test-fatal-xyz" :trace))))
(t/testing "setup! skips invalid entries and installs valid ones"
(t/is (do (l/setup! {"logging-test-setup-xyz" :error
"logging-test-bad-xyz" nil})
true))
(t/is (true? (l/enabled? "logging-test-setup-xyz" :error)))
(t/is (false? (l/enabled? "logging-test-setup-xyz" :bogus)))
(t/is (false? (l/enabled? "logging-test-bad-xyz" :error))))
(t/testing "setup! skips invalid logger keys and installs valid ones"
(t/is (do (l/setup! {"logging-test-key-xyz" :error
"" :error
nil :error})
true))
(t/is (true? (l/enabled? "logging-test-key-xyz" :error))))
(t/testing "safe fallbacks never throw"
(t/is (= "#969896" (l/level->color-safe nil)))
(t/is (= "UNK" (l/level->name-safe nil)))
(t/is (= "#c82829" (l/level->color-safe :fatal)))
(t/is (= "ERR" (l/level->name-safe :fatal))))
(t/testing "console handler survives a nil-level record"
(t/is (nil? (l/console-log-handler
nil nil nil
{::l/logger "logging-test-probe-xyz"
::l/level nil
::l/message (delay "hi")
::l/props {}}))))
(t/testing "console handler skips invalid-logger records"
(t/is (nil? (l/console-log-handler
nil nil nil
{::l/logger nil
::l/level nil
::l/message (delay "hi")
::l/props {}}))))))
#?(:clj
(t/deftest backend-strict-test
(t/testing "fatal does not throw"
(t/is (do (l/enabled? "app" :fatal) true)))
(t/testing "JVM branch still rejects invalid levels loudly"
(t/is (try (l/enabled? "app" nil) false
(catch IllegalArgumentException _ true)))
(t/is (try (l/enabled? "app" :bogus) false
(catch IllegalArgumentException _ true))))))

View File

@ -47,6 +47,7 @@
[common-tests.geom-shapes-tree-seq-test]
[common-tests.geom-snap-test]
[common-tests.geom-test]
[common-tests.logging-test]
[common-tests.logic.chained-propagation-test]
[common-tests.logic.comp-creation-test]
[common-tests.logic.comp-detach-with-nested-test]
@ -128,6 +129,7 @@
'common-tests.geom-shapes-tree-seq-test
'common-tests.geom-snap-test
'common-tests.geom-test
'common-tests.logging-test
'common-tests.logic.chained-propagation-test
'common-tests.logic.comp-creation-test
'common-tests.logic.comp-detach-with-nested-test

View File

@ -50,11 +50,25 @@
(l/set-level! :debug)
(defn- coerce-keyword
"Coerce `v` to a keyword when it is a string or keyword, nil otherwise."
[v]
(when (or (keyword? v) (string? v))
(keyword v)))
(defn ^:export set-logging
([level]
(l/set-level! :app (keyword level)))
(let [level (coerce-keyword level)]
(if (l/valid-level? level)
(l/set-level! "app" level)
(js/console.warn "ignoring invalid log level:" (pr-str level)))))
([ns level]
(l/set-level! (keyword ns) (keyword level))))
(let [ns (coerce-keyword ns)
level (coerce-keyword level)]
(if (and (l/valid-logger? (some-> ns name))
(l/valid-level? level))
(l/set-level! (name ns) level)
(js/console.warn "ignoring invalid logging config:" (pr-str ns) (pr-str level))))))
;; These events are excluded when we activate the :events flag
(def debug-exclude-events

View File

@ -0,0 +1,28 @@
;; This Source Code Form is subject to the terms of the Mozilla Public
;; License, v. 2.0. If a copy of the MPL was not distributed with this
;; file, You can obtain one at http://mozilla.org/MPL/2.0/.
;;
;; Copyright (c) KALEIDOS INC Sucursal en España SL
(ns frontend-tests.debug-logging-test
(:require
[app.common.logging :as l]
[cljs.test :as t :include-macros true]
[debug :as dbg]))
(t/deftest set-logging-test
(t/testing "invalid inputs warn and do not throw"
(t/is (nil? (dbg/set-logging nil)))
(t/is (nil? (dbg/set-logging "bogus")))
(t/is (nil? (dbg/set-logging 123)))
(t/is (nil? (dbg/set-logging nil nil)))
(t/is (nil? (dbg/set-logging "app" "bogus")))
(t/is (nil? (dbg/set-logging "app" nil)))
(t/is (nil? (dbg/set-logging "" "debug"))))
(t/testing "valid inputs install a string logger key"
(dbg/set-logging "app" "debug")
(t/is (true? (l/enabled? "app" :debug)))
(dbg/set-logging "app" "error")
(t/is (true? (l/enabled? "app" :error)))
(t/is (false? (l/enabled? "app" :debug)))
(.delete l/loggers "app")))

View File

@ -35,6 +35,7 @@
[frontend-tests.data.workspace-texts-test]
[frontend-tests.data.workspace-thumbnails-test]
[frontend-tests.data.workspace-versions-test]
[frontend-tests.debug-logging-test]
[frontend-tests.errors-governor-test]
[frontend-tests.errors-test]
[frontend-tests.fonts-test]
@ -169,6 +170,7 @@
'frontend-tests.data.workspace-texts-test
'frontend-tests.data.workspace-thumbnails-test
'frontend-tests.data.workspace-versions-test
'frontend-tests.debug-logging-test
'frontend-tests.errors-governor-test
'frontend-tests.errors-test
'frontend-tests.fonts-test