2015-08-31 13 views
6

Ho scritto test unitari utilizzando clojure.test e ora aggiungo benchmark alla mia applicazione, utilizzando criterium e perforate.Clojure - configura la registrazione `timbre`

Questo funziona bene, ma ho una preoccupazione: sto vedendo un sacco di registri nel mio punto di riferimento. Sto usando timbre e non so come configurarlo dal codice Clojure di Leiningen.

Non ho configurato una mappa di configurazione, anche se afferma nel README di essere super semplice, non ho trovato ulteriore documentazione, e fino ad ora ero felice con i valori predefiniti.

Come si configura la registrazione timbre avere profili diversi tra development, production, e benchmarks (che è un sotto-caso di development).

Nota: nel caso in cui ciò è rilevante, io sto usando un production e development profili in Leiningen già.

risposta

7

Sì, i documenti Timbre potrebbero essere migliorati. Here is a demo program ho usato per capire le impostazioni corrette:

(ns log-timbre.core 
    (:require [clojure.java.io :as io] 
      [taoensso.timbre :as timbre]) 
    (:gen-class)) 

; Set up the name of the log output file and delete any contents from previous runs (the 
; default is to continually append all runs to the file). 
(def log-file-name "log.txt") 
(io/delete-file log-file-name :quiet) 

(timbre/refer-timbre) ; set up timbre aliases 

; The default setup is simple console logging. We with to turn off console logging and 
; turn on file logging to our chosen filename. 
(timbre/set-config! [:appenders :standard-out :enabled?] false) 
(timbre/set-config! [:appenders :spit   :enabled?] true) 
(timbre/set-config! [:shared-appender-config :spit-filename] log-file-name) 

; Set the lowest-level to output as :debug 
(timbre/set-level! :debug) 

(defn my-fn 
    "A simple fn to demonstrate profiling" 
    [] 
    (let [nums (vec (range 1000))] 
    (+ (p :fast-sleep (Thread/sleep 1) 10) 
     (p :slow-sleep (Thread/sleep 2) 32) 
     (p :add (reduce + nums)) 
     (p :sub (reduce - nums)) 
     (p :mult (reduce * nums)) 
     (p :div (reduce/nums))))) 

(defn -main [] 
    (println "Hello, World!") ; a short message to the console 

    ; Demonstrate logging with Timbre 
    (trace "Hello, Timbre! trace") ; will not be logged, below current log-level 
    (debug "Hello, Timbre! debug") 
    (info "Hello, Timbre! info") 
    (warn "Hello, Timbre! warn") 
    (error "Hello, Timbre! error") 
    (fatal "Hello, Timbre! fatal") 

    ; Demonstrate 3 arities of spy 
    (info "Arg-1") 
    (info "Arg-1" :Arg-2) 
    (info "Arg-1" :Arg-2 ["Arg-3"]) 
    (info "Arg-1" :Arg-2 ["Arg-3"] {:Arg 4}) 

    ; Demonstrate 3 arities of spy 
    (assert (= {:a 1}  (spy :info "Spy returns the last value" {:a 1}))) 
    (assert (= 42   (spy (* 6 7)))) ; no level implies :debug 
    (assert (= 42   (spy :warn (* 6 7)))) 
    (assert (= {:a 1}  (spy :error "optional message" {:a 1}))) 

    ; Even exceptions look nice in the logs 
    (error (Exception. "Doh!") "Any extra" :items {:go "here"}) 

    ; Demonstrate profiling with Timbre 
    (info "(my-fn) => " (my-fn)) 
    (profile :info :Arithmetic (dotimes [n 100] (my-fn))) 

    ; Note that when using "lein run", we must place a call to (shutdown-agents) at the end of 
    ; the main program. If this is omitted there is a one minute delay before (non-daemon) 
    ; agent threads will shutdown. For some reason, however, this is not required for "lein 
    ; test". Presumably "lein test" either calls either (shutdown-agents) or (System/exit 0) 
    ; when it is complete. 
    (shutdown-agents) 
) 

Quando viene eseguito sulla riga di comando si otterrà

> lein run 
Hello, World! 

Tutta l'azione andrà nel file log.txt come segue:

> cat log.txt 
2015-Sep-01 13:48:35 -0700 brandy DEBUG [log-timbre.core] - Hello, Timbre! debug 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Hello, Timbre! info 
2015-Sep-01 13:48:35 -0700 brandy WARN [log-timbre.core] - Hello, Timbre! warn 
2015-Sep-01 13:48:35 -0700 brandy ERROR [log-timbre.core] - Hello, Timbre! error 
2015-Sep-01 13:48:35 -0700 brandy FATAL [log-timbre.core] - Hello, Timbre! fatal 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Arg-1 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Arg-1 :Arg-2 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Arg-1 :Arg-2 [Arg-3] 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Arg-1 :Arg-2 [Arg-3] {:Arg 4} 
2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - Spy returns the last value {:a 1} 
2015-Sep-01 13:48:35 -0700 brandy DEBUG [log-timbre.core] - (* 6 7) 42 
2015-Sep-01 13:48:35 -0700 brandy WARN [log-timbre.core] - (* 6 7) 42 
2015-Sep-01 13:48:35 -0700 brandy ERROR [log-timbre.core] - optional message {:a 1} 
2015-Sep-01 13:48:35 -0700 brandy ERROR [log-timbre.core] - Any extra :items {:go here} 
java.lang.Exception: Doh! 
    log-timbre.core/-main/invokeStatic       core.clj: 58 
       log-timbre.core/-main       core.clj  
       clojure.lang.Var.invoke       Var.java: 375 
      user/eval508/invokeStatic form-init3759584005372406642.clj: 1 
         user/eval508 form-init3759584005372406642.clj  
      clojure.lang.Compiler.eval      Compiler.java: 6946 
      clojure.lang.Compiler.eval      Compiler.java: 6936 
      clojure.lang.Compiler.load      Compiler.java: 7393 
     clojure.lang.Compiler.loadFile      Compiler.java: 7331 
clojure.main/load-script/invokeStatic       main.clj: 275 
    clojure.main/init-opt/invokeStatic       main.clj: 277 
       clojure.main/init-opt       main.clj  
clojure.main/initialize/invokeStatic       main.clj: 308 
    clojure.main/null-opt/invokeStatic       main.clj: 342 
       clojure.main/null-opt       main.clj  
     clojure.main/main/invokeStatic       main.clj: 421 
        clojure.main/main       main.clj  
      clojure.lang.RestFn.invoke      RestFn.java: 421 
       clojure.lang.Var.invoke       Var.java: 383 
     clojure.lang.AFn.applyToHelper       AFn.java: 156 
      clojure.lang.Var.applyTo       Var.java: 700 
        clojure.main.main       main.java: 37 

2015-Sep-01 13:48:35 -0700 brandy INFO [log-timbre.core] - (my-fn) => 42 
2015-Sep-01 13:48:36 -0700 brandy INFO [log-timbre.core] - Profiling: :log-timbre.core/Arithmetic 
         Id  nCalls  Min  Max  MAD  Mean Time% Time 
:log-timbre.core/slow-sleep   100  2.0ms  2.0ms 11.0μs  2.0ms  59 208.0ms 
:log-timbre.core/fast-sleep   100  1.0ms  1.0ms 11.0μs  1.0ms  31 108.0ms 
     :log-timbre.core/div   100 33.0μs 420.0μs 37.0μs 70.0μs  2 7.0ms 
     :log-timbre.core/mult   100 16.0μs 384.0μs 28.0μs 42.0μs  1 4.0ms 
     :log-timbre.core/sub   100 10.0μs 308.0μs 27.0μs 33.0μs  1 3.0ms 
     :log-timbre.core/add   100  9.0μs 326.0μs 27.0μs 33.0μs  1 3.0ms 
       Clock Time               100 351.0ms 
      Accounted Time               95 334.0ms 
+0

Sei sicuro di aver bisogno della linea "(timbre/set-config! [: Shared-appender-config: spit-filename] log-file-name)" due volte? – Domchi

+0

Buona cattura! Ho aggiornato il codice. –

+0

questa risposta sembra essere superata con la nuova versione? Ho sbagliato # di args (2) passato a set-config – jdkealy