logging_example.cljs

;; Logging is a bit of a lost art. I see people use it the same way they use
;; println debugging, putting in lots of (log/debug "HERE") kind of stuff, and
;; then removing it afterwards.
;;
;; But with a good logging library these logging statements can continue to
;; provide value, even if (especially if) most of the time you turn them off.
;; For this you need to make good use of log levels like
;; error/warn/info/debug/trace. What follows is an illustrated example of how I
;; tend to use them.

;; These examples use Glogi (https://github.com/lambdaisland/glogi/), but that
;; doesn't matter much. The point is that you have separate logging calls for
;; separate levels, and that you can control those levels in a hierarchical way.

(defn init [api-key]
  ;; Info is good for stuff that happens once, like logging configuration keys
  ;; or environemnt info
  (log/info :init/initialing {:api-key api-key})
  (when-not api-key
    (log/info :init/missing-api-key
              ;; Structured logging doesn't prevent you from having human
              ;; readable messages, ideally you have a convention for these
              {:message "No API_KEY set, integration with FooCorp API will be unavailable."})) ,,, )

(defn handle-button-click [button target]
  ;; Debug is for the main things that happen, so you can see what's going on.
  ;; Log relevant variables so you get some more insight, without it getting too
  ;; noisy. Especially things like ids, primary keys, etc.
  (log/debug :button/clicked {:button button :target target})
  (.then (js/fetch target)
         (fn [response]
           (log/debug :button/fetched {:status (.-status response)})
           ,,,))
  )

(defn process-data [data-rows]
  ;; If logging collections get unwieldy then logging the size of collections
  ;; can already be helpful.
  (log/debug :process-data/starting {:row-count (count data-rows)})
  (doseq [row data-rows]
    ;; For stuff that happens in loops or that happens a lot, use trace. Trace
    ;; can be noisy. That's the point of trace.
    (log/trace :process-data/processing {:row row})
    (let [result
          (try
            (process-row row)
            (catch :default e
              (log/error :process-data/error {:row row}
                         :exception e)))]
      ,,,
      (log/trace :data/processed {:row-id (:id row) :result result}))

    ;; Notice "processing" vs "processed", most of the time you either log
    ;; before you do some side effectful thing, or after you're done with it. I
    ;; use a convention of continuos present vs past tense to indicate this.
    ))

;; Now comes the fun part, once these calls are in, you can control the levels
;; separately, and per namespace (or part of the namespace hierarchy).

;; During development you can use settings like this:

(log/set-levels
 ;; default is info, so error/warn/info are always shown, also from third party
 ;; libraries
 {::glogi/root :info
  ;; For our own stuff we want to default to debug, generally
  'lambdaisland :debug
  'co.gaiwan :debug
  ;; When you're actively working on something and want to see the fine details,
  ;; you can temporarily switch it to trace for a certain namespace
  'co.gaiwan.itrev.events :trace
  ;; Maybe some library abuses "info" and is still quite noisy, so you reduce
  ;; its noise level
  'some.third.party :warn
  })

;; When deploying you can turn most of it off, besides warnings and errors

(log/set-levels {::glogi/root :warn})

;; Note that you can also use `:closure-defines` to turn logging off, in which
;; case the log/... calls will be stripped out of the code