A simple, fast, monitoring profiler for Clojure/Script.
Usage: wrap+name interesting body exprs with the p macro. Then activate
profiling of these wrapped exprs using the profiled or profile macros:
(profiled {} (p :my-fn (my-fn))) ; Returns [<body-result> <?pstats>] (profile {} (p :my-fn (my-fn))) ; Returns <body-result>, dispatches ; ?pstats to any registered handlers.
Extensive facilities are provided for compile-time elision and runtime filtering.
See the relevant docstrings for more info:
p, profiled, profile, add-handler! ; Core API
(p [opts & body] [id & body]) ; e.g. (p ::my-pid (do-work))
(profiled [opts & body]) ; e.g. (profiled {:level 2} (my-fn))
(profile [opts & body]) ; e.g. (profiled {:level 2} (my-fn))
(add-handler! [handler-id ns-pattern handler-fn])
How/where to use this library: Tufte profiling is highly optimized: even without elision, you can usually leave profiling enabled in production (e.g. for sampled profiling, or to detect unusual performance behaviour). Tufte's stats maps are well suited to programmatic monitoring.
A simple, fast, monitoring profiler for Clojure/Script.
Usage: wrap+name interesting body exprs with the `p` macro. Then activate
profiling of these wrapped exprs using the `profiled` or `profile` macros:
(profiled {} (p :my-fn (my-fn))) ; Returns [<body-result> <?pstats>]
(profile {} (p :my-fn (my-fn))) ; Returns <body-result>, dispatches
; ?pstats to any registered handlers.
Extensive facilities are provided for compile-time elision and runtime
filtering.
See the relevant docstrings for more info:
`p`, `profiled`, `profile`, `add-handler!` ; Core API
(p [opts & body] [id & body]) ; e.g. `(p ::my-pid (do-work))`
(profiled [opts & body]) ; e.g. `(profiled {:level 2} (my-fn))`
(profile [opts & body]) ; e.g. `(profiled {:level 2} (my-fn))`
(add-handler! [handler-id ns-pattern handler-fn])
How/where to use this library:
Tufte profiling is highly optimized: even without elision, you can usually
leave profiling enabled in production (e.g. for sampled profiling, or to
detect unusual performance behaviour). Tufte's stats maps are well suited
to programmatic monitoring.(-elide? level-form ns-str-form)Returns true iff level or ns are compile-time filtered.
Returns true iff level or ns are compile-time filtered.
(accumulate-stats stats-accumulator [result ?pstats])Experimental, subject to change!
Experimental, subject to change!
(add-basic-println-handler! {:keys [ns-pattern format-columns]
:or {ns-pattern "*"
format-columns stats/all-format-columns}})Adds a simple handler that logs profile stats output with println.
Adds a simple handler that logs `profile` stats output with `println`.
(add-handler! handler-id handler-fn)(add-handler! handler-id ns-pattern handler-fn)Use this to register interest in stats output produced by profile calls.
Each registered handler-fn will be called as:
(handler-fn {:ns-str _ :level _ :?id _ :?data _ :pstats _ :pstats-str_ _})
Map args:
:ns-str - Namespace string where profile call took place
:level - Level e/o #{0 1 2 3 4 5}, given in (profile {:level _} ...)
:?id - Optional id, given in (profile {:id _} ...)
:?data - Optional arb data, given in (profile {:data _} ...)
:pstats - As in (second (profiled ...)). Derefable, mergeable.
:pstats-str_ - `(delay (format-pstats pstats))
Error handling (NB):
Handler errors will be silently swallowed. Please try/catch and
appropriately deal with (e.g. log) possible errors within handler-fn.
Async/blocking:
handler-fn should ideally be non-blocking, or reasonably cheap. Handler
dispatch occurs through a 1-thread 1k-buffer dropping queue.
Ns filtering:
Provide an optional ns-pattern arg to only call handler for matching
namespaces. See compile-ns-filter docstring for details on ns-pattern.
Handler ideas:
Save to a db, log, put! to an appropriate core.async channel, filter,
aggregate, use for a realtime analytics dashboard, examine for outliers
or unexpected output, ...
Use this to register interest in stats output produced by `profile` calls.
Each registered `handler-fn` will be called as:
(handler-fn {:ns-str _ :level _ :?id _ :?data _ :pstats _ :pstats-str_ _})
Map args:
:ns-str - Namespace string where `profile` call took place
:level - Level e/o #{0 1 2 3 4 5}, given in `(profile {:level _} ...)`
:?id - Optional id, given in `(profile {:id _} ...)`
:?data - Optional arb data, given in `(profile {:data _} ...)`
:pstats - As in `(second (profiled ...))`. Derefable, mergeable.
:pstats-str_ - `(delay (format-pstats pstats))
Error handling (NB):
Handler errors will be silently swallowed. Please `try`/`catch` and
appropriately deal with (e.g. log) possible errors *within* `handler-fn`.
Async/blocking:
`handler-fn` should ideally be non-blocking, or reasonably cheap. Handler
dispatch occurs through a 1-thread 1k-buffer dropping queue.
Ns filtering:
Provide an optional `ns-pattern` arg to only call handler for matching
namespaces. See `compile-ns-filter` docstring for details on `ns-pattern`.
Handler ideas:
Save to a db, log, `put!` to an appropriate `core.async` channel, filter,
aggregate, use for a realtime analytics dashboard, examine for outliers
or unexpected output, ...(capture-time! id nano-secs-elapsed)(capture-time! pdata id nano-secs-elapsed)Note: this is a low-level primitive for advanced users! Can be useful when tracking time across arbitrary thread boundaries or for async jobs / callbacks / etc.
See new-pdata for more info on low-level primitives.
Note: this is a low-level primitive for advanced users! Can be useful when tracking time across arbitrary thread boundaries or for async jobs / callbacks / etc. See `new-pdata` for more info on low-level primitives.
(chance p)Returns true with 0<p<1 probability.
Returns true with 0<`p`<1 probability.
(compile-ns-filter ns-pattern)Returns (fn [?ns]) -> truthy. Some example patterns: "foo.bar", "foo.bar.", #{"foo" "bar"}, {:whitelist ["foo.bar."] :blacklist ["baz.*"]}
Returns (fn [?ns]) -> truthy. Some example patterns:
"foo.bar", "foo.bar.*", #{"foo" "bar"},
{:whitelist ["foo.bar.*"] :blacklist ["baz.*"]}(defnp name doc-string? attr-map? [params*] prepost-map? body)(defnp name doc-string? attr-map? ([params*] prepost-map? body) + attr-map?)(defnp &form &env & sigs)Like defn but wraps fn bodies with p macro.
Like `defn` but wraps fn bodies with `p` macro.
(fnp name? ([params*] prepost-map? body) +)(fnp name? [params*] prepost-map? body)(fnp &form &env & sigs)Like fn but wraps fn bodies with p macro.
Like `fn` but wraps fn bodies with `p` macro.
(format-pstats ps & [{:keys [columns] :or {columns stats/all-format-columns}}])Formats given pstats to a string table. Accounted < Clock => Some work was done that wasn't tracked by any p forms. Accounted > Clock => Nested p forms, and/or parallel threads.
Formats given pstats to a string table. Accounted < Clock => Some work was done that wasn't tracked by any p forms. Accounted > Clock => Nested p forms, and/or parallel threads.
(may-profile? level)(may-profile? level ns)Returns true iff level and ns are runtime unfiltered.
Returns true iff level and ns are runtime unfiltered.
(merge-pstats)(merge-pstats ps0)(merge-pstats ps0 ps1)Lossless unless data to merge are very large.
Lossless unless data to merge are very large.
(new-pdata)(new-pdata {:keys [dynamic? nmax] :or {dynamic? true nmax default-nmax}})Note: this is a low-level primitive for advanced users!
Returns a new pdata object for use with with-profiling and/or capture-time!.
Deref to get pstats:
(let [pd (new-pdata) t0 (System/nanoTime)] (with-profiling pd {} (p :foo (Thread/sleep 100)) (capture-time! pd :bar (- t0 (System/nanoTime)))) @pd)
Dynamic (thread-safe) by default. WARNING: don't change this default unless you're very sure the resulting pdata object will not be concurrently modified across threads. Concurrent modification will lead to bad data and/or exceptions!
Note: this is a low-level primitive for advanced users!
Returns a new pdata object for use with `with-profiling` and/or `capture-time!`.
Deref to get pstats:
(let [pd (new-pdata)
t0 (System/nanoTime)]
(with-profiling pd {}
(p :foo (Thread/sleep 100))
(capture-time! pd :bar (- t0 (System/nanoTime))))
@pd)
Dynamic (thread-safe) by default.
*WARNING*: don't change this default unless you're very sure the resulting
pdata object will not be concurrently modified across threads. Concurrent
modification will lead to bad data and/or exceptions!(p id & body)(p opts & body)Profiling spy. Always executes body, and always returns <body-result>.
When [ns level] unelided and profiling is active, records execution time of body.
Compile-time opts:
:id - Id for this body in stats output (e.g. ::my-fn-call)
:level - e/o #{0 1 2 3 4 5} ; Default is 5
Profiling spy. Always executes body, and always returns <body-result>.
When [ns level] unelided and profiling is active, records execution
time of body.
Compile-time opts:
:id - Id for this body in stats output (e.g. `::my-fn-call`)
:level - e/o #{0 1 2 3 4 5} ; Default is `5`(profile opts & body)Always executes body, and always returns <body-result>.
When [ns level] unelided and [ns level when] unfiltered, executes body
with profiling active and dispatches stats to any registered handlers
(see add-handler!).
Handy if you'd like to consume/aggregate stats output later/elsewhere.
Otherwise see profiled.
Compile-time opts:
:level - e/o #{0 1 2 3 4 5} ; Default is 5
:dynamic? - Use multi-threaded profiling? ; Default is false
:nmax - ~Max captures per id before compaction ; Default is 8e5
:when - Optional arbitrary conditional form (e.g. boolean expr)
:id - Optional stats id provided to handlers (e.g. ::my-stats-1)
:data - Optional arbitrary data provided to handlers
Note on laziness: Please note that lazy seqs and other forms of laziness (e.g. delays) will only contribute to profiling results if/when evaluation actually occurs. This is intentional and a useful property. Compare:
(profiled {} (delay (Thread/sleep 2000))) ; Doesn't count sleep (profiled {} @(delay (Thread/sleep 2000))) ; Does count sleep
Always executes body, and always returns <body-result>.
When [ns level] unelided and [ns level `when`] unfiltered, executes body
with profiling active and dispatches stats to any registered handlers
(see `add-handler!`).
Handy if you'd like to consume/aggregate stats output later/elsewhere.
Otherwise see `profiled`.
Compile-time opts:
:level - e/o #{0 1 2 3 4 5} ; Default is `5`
:dynamic? - Use multi-threaded profiling? ; Default is `false`
:nmax - ~Max captures per id before compaction ; Default is 8e5
:when - Optional arbitrary conditional form (e.g. boolean expr)
:id - Optional stats id provided to handlers (e.g. `::my-stats-1`)
:data - Optional arbitrary data provided to handlers
Note on laziness:
Please note that lazy seqs and other forms of laziness (e.g. delays)
will only contribute to profiling results if/when evaluation actually
occurs. This is intentional and a useful property. Compare:
(profiled {} (delay (Thread/sleep 2000))) ; Doesn't count sleep
(profiled {} @(delay (Thread/sleep 2000))) ; Does count sleep(profiled opts & body)Always executes body, and always returns [<body-result> <?pstats>].
When [ns level] unelided and [ns level when] unfiltered, executes body
with profiling active.
Handy if you'd like to consume stats output directly.
Otherwise see profile.
pstats objects are derefable and mergeable:
Full set of :stats keys:
:n :min :max :mean :mad :sum :p50 :p90 :p95 :p99
Compile-time opts:
:level - e/o #{0 1 2 3 4 5} ; Default is 5
:dynamic? - Use multi-threaded profiling? ; Default is false
:nmax - ~Max captures per id before compaction ; Default is 8e5
:when - Optional arbitrary conditional form (e.g. boolean expr)
Note on laziness: Please note that lazy seqs and other forms of laziness (e.g. delays) will only contribute to profiling results if/when evaluation actually occurs. This is intentional and a useful property. Compare:
(profiled {} (delay (Thread/sleep 2000))) ; Doesn't count sleep (profiled {} @(delay (Thread/sleep 2000))) ; Does counts sleep
Always executes body, and always returns [<body-result> <?pstats>].
When [ns level] unelided and [ns level `when`] unfiltered, executes body
with profiling active.
Handy if you'd like to consume stats output directly.
Otherwise see `profile`.
`pstats` objects are derefable and mergeable:
- @pstats -> {:stats {:n _ :min _ ...} :clock {:t0 _ :t1 _ :total _}}
- @(merge-pstats ps1 ps2) -> {:stats {:n _ :min _ ...} :clock {:t0 _ :t1 _ :total _}}
Full set of `:stats` keys:
:n :min :max :mean :mad :sum :p50 :p90 :p95 :p99
Compile-time opts:
:level - e/o #{0 1 2 3 4 5} ; Default is `5`
:dynamic? - Use multi-threaded profiling? ; Default is `false`
:nmax - ~Max captures per id before compaction ; Default is 8e5
:when - Optional arbitrary conditional form (e.g. boolean expr)
Note on laziness:
Please note that lazy seqs and other forms of laziness (e.g. delays)
will only contribute to profiling results if/when evaluation actually
occurs. This is intentional and a useful property. Compare:
(profiled {} (delay (Thread/sleep 2000))) ; Doesn't count sleep
(profiled {} @(delay (Thread/sleep 2000))) ; Does counts sleep(profiling?)Returns e/o #{nil :thread :dynamic}.
Returns e/o #{nil :thread :dynamic}.
(refer-tufte)(require '[taoensso.tufte :as tufte :refer [defnp p profiled profile]])
(require '[taoensso.tufte :as tufte :refer [defnp p profiled profile]])
(set-min-level! level)Sets root binding of minimum profiling level, e/o #{0 1 2 3 4 5 6}. 0 => Enable all profiling. 6 => Disable all profiling.
Sets root binding of minimum profiling level, e/o #{0 1 2 3 4 5 6}.
0 => Enable all profiling.
6 => Disable all profiling.(set-ns-pattern! ns-pattern)Sets root binding of namespace filter.
See compile-ns-filter docstring for details on ns-pattern arg.
Sets root binding of namespace filter. See `compile-ns-filter` docstring for details on `ns-pattern` arg.
(stats-accumulator)(stats-accumulator init-pstats)Experimental, subject to change! Small util to help collect (merge) pstats from multiple runs or threads.
Returns a stateful StatsAccumulator, acc:
@acc ; Returns current pstats(acc <pstats>) ; Synchronously merges given pstats into accumulatorNote that you may want some kind of async/buffer/serialization mechanism in front of merge calls (e.g. an agent).
Experimental, subject to change! Small util to help collect (merge) pstats from multiple runs or threads. Returns a stateful StatsAccumulator, `acc`: - `@acc` ; Returns current pstats - `(acc <pstats>)` ; Synchronously merges given pstats into accumulator Note that you may want some kind of async/buffer/serialization mechanism in front of merge calls (e.g. an agent).
(with-min-level level & body)(with-min-level &form &env level & body)Executes body with dynamic minimum profiling level, e/o #{0 1 2 3 4 5 6}. 0 => Enable all profiling. 6 => Disable all profiling.
Executes body with dynamic minimum profiling level, e/o #{0 1 2 3 4 5 6}.
0 => Enable all profiling.
6 => Disable all profiling.(with-ns-pattern ns-pattern & body)(with-ns-pattern &form &env ns-pattern & body)Executes body with dynamic namespace filter.
See compile-ns-filter docstring for details on ns-pattern arg.
Executes body with dynamic namespace filter. See `compile-ns-filter` docstring for details on `ns-pattern` arg.
(with-profiling pdata {:keys [dynamic? nmax] :or {nmax default-nmax}} & body)(with-profiling &form
&env
pdata
{:keys [dynamic? nmax] :or {nmax default-nmax}}
&
body)Note: this is a low-level primitive for advanced users!
Enables p forms in body and returns body's result.
See new-pdata for more info on low-level primitives.
Note: this is a low-level primitive for advanced users! Enables `p` forms in body and returns body's result. See `new-pdata` for more info on low-level primitives.
cljdoc builds & hosts documentation for Clojure/Script libraries
| Ctrl+k | Jump to recent docs |
| ← | Move to previous article |
| → | Move to next article |
| Ctrl+/ | Jump to the search field |