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. Provides extensive facilities 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-id (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 handler-fn dispatch-opts]) How/where to use this library: Tufte profiling is highly optimized: even without elision, you can usually leave profiling active in production (e.g. for sampled profiling, or to detect unusual performance behaviour). Tufte's pstats data is well suited to programmatic monitoring.
(accumulating-handler sacc)
Takes a `StatsAccumulator` and returns a simple handler fn for use with `add-handler!` that merges `profile` pstats into the given accumulator. See `stats-accumulator` for more info.
(add-handler! handler-id handler-fn)
(add-handler! handler-id handler-fn dispatch-opts)
Registers given profiling handler and returns {<handler-id> <dispatch-opts>} for all handlers now registered. `handler-fn` should be a fn of 1-2 arities: ([handler-arg]) => Handle the given argument (e.g. write to disk/db, etc.) ([]) => Optional arity, called exactly once on system shutdown. Provides an opportunity for handler to close/release any resources that it may have opened/acquired. See the relevant docstring/s for `handler-arg` details. Handler ideas: Save to a db, `tap>`, log, `put!` to an appropriate `core.async` channel, filter, aggregate, use for a realtime analytics dashboard, examine for outliers or unexpected data, etc. Dispatch options include: `async` (Clj only) Options for running handler asynchronously via `taoensso.encore/runner`, {:keys [mode buffer-size n-threads daemon-threads? ...]} Supports `:blocking`, `:dropping`, and `:sliding` back-pressure modes. NB handling order may be non-sequential when `n-threads` > 1. `sample` Optional sample rate ∈ℝ[0,1]. When present, handle only this (random) proportion of args: 1.0 => handle every arg 0.0 => noop every arg 0.5 => handle random 50% of args `rate-limit` Optional rate limit spec as provided to `taoensso.encore/limiter`, {<limit-id> [<n-max-calls> <msecs-window>]}. Examples: {"1/sec" [1 1000]} => Max 1 call per 1000 msecs {"1/sec" [1 1000] "10/min" [10 60000]} => Max 1 call per 1000 msecs, and 10 calls per 60 secs `ns-filter` - Namespace filter as in `set-ns-filter!` `kind-filter` - Kind filter as in `set-kind-filter!` (when relevant) `id-filter` - Id filter as in `set-id-filter!` (when relevant) `min-level` - Minimum level as in `set-min-level!` `filter-fn` Optional (fn allow? [handler-arg]) that must return truthy for `handler-fn` to be called for given `handler-arg`. When present, called *after* sampling and other filters, but before rate limiting. `error-fn` - (fn [{:keys [handler-id error]}]) to call on handler error. `backp-fn` - (fn [{:keys [handler-id ]}]) to call on handler back pressure.
(capture-time! id nano-secs-elapsed)
(capture-time! pdata id nano-secs-elapsed)
Low-level primitive for advanced users. Useful when tracking time across thread boundaries and/or for async jobs / callbacks / etc. See `new-pdata` for more info on low-level primitives. See also `capture-time!*`.
(capture-time!* id nano-secs-elapsed)
(capture-time!* pdata id nano-secs-elapsed)
Like `capture-time!` but: a function, and does not collect callsite location info.
(defnp name doc-string? attr-map? [params*] prepost-map? body)
(defnp name doc-string? attr-map? ([params*] prepost-map? body) + attr-map?)
Like `defn` but wraps fn bodies with `p` macro.
(defnp- name doc-string? attr-map? [params*] prepost-map? body)
(defnp- name doc-string? attr-map? ([params*] prepost-map? body) + attr-map?)
Like `defn-` but wraps fn bodies with `p` macro.
(fnp name? ([params*] prepost-map? body) +)
(fnp name? [params*] prepost-map? body)
Like `fn` but wraps fn bodies with `p` macro.
(format-grouped-pstats m)
(format-grouped-pstats m
{:keys [group-sort-fn format-pstats-opts]
:or {group-sort-fn (fn [m]
(get-in m [:clock :total] 0))}})
Alpha, subject to change. Takes a map of {<profile-id> <pstats>} and formats a combined output string using `format-pstats`. See also example Clj project.
(format-id-abbr)
(format-id-abbr n-full)
Returns a cached (fn [id]) => abbreviated id with at most `n-full` unabbreviated namespace parts. Example: ((format-id-abbr 0) :foo.bar/baz) => :f.b/baz ((format-id-abbr 1) 'foo.bar/baz) => 'f.bar/baz ((format-id-abbr 2) "foo.bar/baz") => "foo.bar/baz"
(format-pstats ps)
(format-pstats ps opts)
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.
(get-handlers)
Returns {<handler-id> <dispatch-opts>} for all registered profiling handlers.
(merge-pstats)
(merge-pstats ps0)
(merge-pstats ps0 ps1)
(merge-pstats nmax ps0 ps1)
Merges given pstats, compacting as necessary. Merged statistics are lossless unless data to merge are very large.
(new-pdata)
(new-pdata {:keys [dynamic? nmax] :or {dynamic? true nmax default-nmax}})
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)))) (deref 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 {:keys [id level]} & body)
Profiling spy. Use this to wrap forms that should be timed during profiling: - Always executes body and returns <body-result>. - When profiling is active (via `profiled` or `profile`), records body's execution time. Options include: `:id` - Form id for this body in pstats (e.g. `::my-fn-call`) `:level` - Integer (default 5)
(print-handler)
(print-handler {:keys [format-pstats-opts]})
Returns a simple handler fn for use with `add-handler!` that: 1. Formats `profile` pstats with `format-pstats`, and 2. Prints the resulting string table with `print`. Options: `:format-pstats-opts` - Opts map provided to `format-pstats`
(profile {:keys [id level sample rate-limit filter]} & body)
Use this to start profiling: - Always executes body and returns <body-result>. - When profiling is unfiltered [*1], records execution time of all `p` forms and dispatches map [*2] to any registered handlers (see `add-handler!`). [*1] See `set-ns-filter!`, `set-id-filter!`, `set-min-level!`, etc. [*2] {:keys [instant id level ns line data pstats pstats-str_]} Decouples creation and consumption of pstats, handy if you'd like to consume/aggregate pstats later/elsewhere. Otherwise see `profiled`. `pstats` objects are derefable and mergeable: - @pstats => {:clock {:keys [t0 t1 total]}, :stats {<id> {:keys [n sum ...]}}} - @(merge-pstats ps1 ps2) => {:clock {:keys [t0 t1 total]}, :stats {<id> {:keys [n sum ...]}}} Full set of keys in above `:stats` maps: :n :min :max :mean :mad :sum :p25 :p50 :p75 :p90 :p95 :p99 :loc :last All values are numerical (longs or doubles), except for `:loc` which is a map of `p` callsite location information, or set of such maps, e.g.: #{{:ns "my-ns", :file "/tmp/my-ns.clj", :line 122, :column 21}} Options include: `:dynamic?` - Use multi-threaded profiling? (default false). `:nmax` - Max captures per `p` id before compaction (default 8e5). `:id` - Profiling id provided to handlers (e.g. `::my-profiling-id`). `:level` - Integer (default 5), must >= active minimum level to profile. `:sample` - Sample rate ∈ℝ[0,1], profile only this proportion of calls. `:rate-limit` - {<limit-id> [<n-max-calls> <msecs-window>]} spec, profile only calls that don't exceed the specified limits. `:filter` - Profile only when filter form (e.g. boolean expr) is truthy. Laziness in body: Lazy seqs and other forms of laziness (e.g. delays) in body 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 Async code in body: Execution time of any code in body that runs asynchronously on a different thread will generally NOT be automatically captured by default. :dynamic? can be used to support capture in cases where Clojure's binding conveyance applies (e.g. futures, agents, pmap). Just make sure that all work you want to capture has COMPLETED before the `profiled` form ends- for example, by blocking on pending futures. In other advanced cases (notably core.async `go` blocks), please see `with-profiling` and `capture-time!`. `core.async` warning: `core.async` code can be difficult to profile correctly without a deep understanding of precisely what it's doing under-the-covers. Some general recommendations that can help keep things simple: - Try minimize the amount of code + logic in `go` blocks. Use `go` blocks for un/parking to get the data you need, then pass the data to external fns. Profile these fns (or in these fns), not in your `go` blocks. - In particular: you MUST NEVER have parking calls inside `(profiled {:dynamic? false} ...)`. This can lead to concurrency exceptions. If you must profile code within a go block, and you really want to include un/parking times, use `(profiled {:dynamic? true} ...)` instead.
(profiled {:keys [id level sample rate-limit filter]} & body)
Use this to start profiling: - Always executes body and returns [<body-result> <?pstats>]. - When profiling is unfiltered [*1], records execution time of all `p` forms. [*1] See `set-ns-filter!`, `set-id-filter!`, `set-min-level!`, etc. Handy if you'd like to consume pstats directly, otherwise see `profile`. `pstats` objects are derefable and mergeable: - @pstats => {:clock {:keys [t0 t1 total]}, :stats {<id> {:keys [n sum ...]}}} - @(merge-pstats ps1 ps2) => {:clock {:keys [t0 t1 total]}, :stats {<id> {:keys [n sum ...]}}} Full set of keys in above `:stats` maps: :n :min :max :mean :mad :sum :p25 :p50 :p75 :p90 :p95 :p99 :loc :last All values are numerical (longs or doubles), except for `:loc` which is a map of `p` callsite location information, or set of such maps, e.g.: #{{:ns "my-ns", :file "/tmp/my-ns.clj", :line 122, :column 21}} Options include: `:dynamic?` - Use multi-threaded profiling? (default false). `:nmax` - Max captures per `p` id before compaction (default 8e5). `:id` - Profiling id provided to handlers (e.g. `::my-profiling-id`). `:level` - Integer (default 5), must >= active minimum level to profile. `:sample` - Sample rate ∈ℝ[0,1], profile only this proportion of calls. `:rate-limit` - {<limit-id> [<n-max-calls> <msecs-window>]} spec, profile only calls that don't exceed the specified limits. `:filter` - Profile only when filter form (e.g. boolean expr) is truthy. Laziness in body: Lazy seqs and other forms of laziness (e.g. delays) in body 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 Async code in body: Execution time of any code in body that runs asynchronously on a different thread will generally NOT be automatically captured by default. :dynamic? can be used to support capture in cases where Clojure's binding conveyance applies (e.g. futures, agents, pmap). Just make sure that all work you want to capture has COMPLETED before the `profiled` form ends- for example, by blocking on pending futures. In other advanced cases (notably core.async `go` blocks), please see `with-profiling` and `capture-time!`. `core.async` warning: `core.async` code can be difficult to profile correctly without a deep understanding of precisely what it's doing under-the-covers. Some general recommendations that can help keep things simple: - Try minimize the amount of code + logic in `go` blocks. Use `go` blocks for un/parking to get the data you need, then pass the data to external fns. Profile these fns (or in these fns), not in your `go` blocks. - In particular: you MUST NEVER have parking calls inside `(profiled {:dynamic? false} ...)`. This can lead to concurrency exceptions. If you must profile code within a go block, and you really want to include un/parking times, use `(profiled {:dynamic? true} ...)` instead.
(refer-tufte)
(require '[taoensso.tufte :as tufte :refer [defnp p profiled profile]])
(remove-handler! handler-id)
Deregisters profiling handler with given id, and returns {<handler-id> <disaptch-opts>} for all profiling handlers still registered.
(set-id-filter! id-filter)
Sets profiling id filter based on given `id-filter` spec. `id-filter` may be: - A regex pattern of id/s to allow. - A str/kw/sym, in which "*"s act as wildcards. - A vector or set of regex patterns or strs/kws/syms. - {:allow <spec> :deny <spec>} with specs as above.
(set-min-level! min-level)
(set-min-level! ns-filter min-level)
Sets minimum profiling level based on given `min-level` spec. `min-level` may be: - An integer. - A level keyword (see `level-aliases` var for details). If `ns-filter` is provided, then the given minimum level will apply only for namespaces that match `ns-filter`. See `set-ns-filter!` for details.
(set-ns-filter! ns-filter)
Sets profiling namespace filter based on given `ns-filter` spec. `ns-filter` may be: - A regex pattern of namespace/s to allow. - A str/kw/sym, in which "*"s act as wildcards. - A vector or set of regex patterns or strs/kws/syms. - {:allow <spec> :deny <spec>} with specs as above.
(stats-accumulator)
Experimental, subject to change! Small util to help merge pstats from multiple runs and/or threads. Returns a stateful `StatsAccumulator` (`sacc`) with: - (sacc <profile-id> <pstats>) ; Merges given pstats under given profile id - @sacc ; Drains accumulator and returns drained ; {<profile-id> <merged-pstats>} Note that for performance reasons, you'll likely want some kind of async/buffer/serialization mechanism in front of merge calls. One common pattern using `accumulating-handler` is to create a system-wide accumulator that you deref every n minutes/etc. to get a view of system-wide performance over the period, e.g.: (defonce my-sacc (stats-accumulator) ; Create an accumulator (add-handler! :my-sacc (accumulating-handler my-sacc)) ; Register handler (defonce my-sacc-drainer ;; Drain and print formatted stats every minute (future (while true (when-let [m (not-empty @my-sacc)] (println (format-grouped-pstats m))) (Thread/sleep 60000)))) (profile ...) ; Used elsewhere in your application, e.g. ; wrapping relevant Ring routes in a web application. See example clj project for more details.
(telemere-handler)
(telemere-handler {:keys [signal-level format-pstats-opts]})
Returns nil if Telemere isn't present, otherwise- Returns a simple handler fn for use with `add-handler!` that: 1. Formats `profile` pstats with `format-pstats`, and 2. Generates an appropriate signal with Telemere. Options: `:format-pstats-opts` - Opts map provided to `format-pstats` `:signal-level` - Signal level, or ifn to map profiling->signal level
(with-id-filter id-filter form)
Executes form with given profiling id filter in effect. See `set-id-filter!` for details.
(with-min-level min-level form)
(with-min-level ns-filter min-level form)
Executes form with given minimum profiling level in effect. See `set-min-level!` for details.
(with-ns-filter ns-filter form)
Executes form with given profiling namespace filter in effect. See `set-ns-filter!` for details.
(with-profiling pdata {:keys [dynamic? nmax] :or {nmax default-nmax}} & body)
Low-level primitive for advanced users. Executes body with profiling active, and returns <body-result>. If `:dynamic?` is false (default), body's evaluation MUST begin and end without interruption on the same thread. In particular this means that body MUST NOT contain any parking `core.async` calls. See `new-pdata` for more info on low-level primitives.
cljdoc is a website building & hosting documentation for Clojure/Script libraries
× close