inspector

See what your functions are doing.

Install

Check https://clojars.org/org.clojars.akshay/inspector

Features

• Export data when a function executes. Exports:
  • :fn-name namespace qualified name
  • :fn-args arguments
  • :id uniquely identifies each function call
  • :tid thread id
  • :c-id caller functions id
  • :c-tid caller functions thread id
  • :c-chain vector of function calls (ids) which eventually lead to call to current fn
  • :uuid
  • :execution-time time duration (nano second) taken by function to execute
  • :e error
  • :fn-rv return value
• Thread safe
• Error handling
• Modes
  • Repl debug
  • Omnipresent debug: capture data for all^* functions, across all threads, all the time

Basic Usage

Setup

(require '[inspector.inspector :as i])

; i/get-vars returns a set of all vars which corresponds to functions
; defined in all namespaces, which matches provided regex #"your-code-base.*"
(def my-vars
   ; Generally you would want to track all functions that you have defined.
   (i/get-vars #"your-code-base.*"))

REPL debug

Visualizing all function calls

; visualizing all the function being called by (my-fn arg1 arg2 argn)
; print to std-out
(i/iprint my-vars #(my-fn arg1 arg2 argn))

; write to a file instead
(i/ispit "/tmp/hierarchy.log" my-vars #(my-fn arg1 arg2 argn))

Example output

From inspector.test.inspector-test

Time: Tue Jan 23 16:28:30 IST 2024
Г-- inspector.test.inspector-test/parallel (1)
|  Г-- inspector.test.inspector-test/simple (0)
|  |  Г-- inspector.test.inspector-test/simplest (0)
|  |  L-- 0
|  L-- 0
|  Г-- inspector.test.inspector-test/simple (1)
|  |  Г-- inspector.test.inspector-test/simplest (1)
|  |  L-- 1
|  L-- 1
L-- [0 1]

Note:
1 is an argument.
Г-- inspector.test.inspector-test/parallel (1)
.
.
.
L-- [0 1]
[0 1] is thre return value on calling (parallel 1)

Show calls to database

; Calling you function to see if its performing any CRUD operations in mongodb (or any other library/libraries)
(i/iprint-tracked 
   (i/get-vars #"mongodb.*")  ; Track all functions defined in mongodb library
   my-vars
   #(my-fn arg1 arg2 argn))

; you can write to file instead
(i/ispit-tracked
   (i/get-vars #"mongodb.*") 
   my-vars
   #(my-fn arg1 arg2 argn))

Example output

From inspector.test.inspector-test

Time: Tue Jan 23 17:32:22 IST 2024
♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ 
call-chain: ["inspector.test.inspector-test/parallel" "inspector.test.inspector-test/simple" "inspector.test.inspector-test/simplest"]
name: inspector.test.inspector-test/simplest
args: (1)
rv: 1
♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ ♤ ♧ ♡ ♢ 
call-chain: ["inspector.test.inspector-test/parallel" "inspector.test.inspector-test/simple" "inspector.test.inspector-test/simplest"]
name: inspector.test.inspector-test/simplest
args: (0)
rv: 0

Note: 
call-chain: shows the order in which different functions were called which finally resulted in call to a tracked fn.

Get raw data

; rv is return value of (my-fn arg1 arg2 argn)
(let [{:keys [e rv fn-call-records]} (i/export-raw my-vars #(my-fn arg1 arg2 argn)]
   fn-call-records)

Example output

From inspector.test.capture-test

; fn-call-records
[{:c-chain []    :id 1 :c-id nil :fn-name "inspector.test.capture-test/parallel" :fn-args (1) :tid 34 :c-tid nil :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e"}
 {:c-chain [1]   :id 2 :c-id 1   :fn-name "inspector.test.capture-test/simple"   :fn-args (0) :tid 30 :c-tid 34  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e"}
 {:c-chain [1 2] :id 4 :c-id 2   :fn-name "inspector.test.capture-test/simplest" :fn-args (0) :tid 30 :c-tid 30  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e"}
 {:c-chain [1]   :id 3 :c-id 1   :fn-name "inspector.test.capture-test/simple"   :fn-args (1) :tid 29 :c-tid 34  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e"}
 {:c-chain [1 2] :id 4 :c-id 2   :fn-name "inspector.test.capture-test/simplest" :fn-args (0) :tid 30 :c-tid 30  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e" :execution-time 6584   :fn-rv 0}
 {:c-chain [1 3] :id 5 :c-id 3   :fn-name "inspector.test.capture-test/simplest" :fn-args (1) :tid 29 :c-tid 29  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e"}
 {:c-chain [1]   :id 2 :c-id 1   :fn-name "inspector.test.capture-test/simple"   :fn-args (0) :tid 30 :c-tid 34  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e" :execution-time 49583  :fn-rv 0}
 {:c-chain [1 3] :id 5 :c-id 3   :fn-name "inspector.test.capture-test/simplest" :fn-args (1) :tid 29 :c-tid 29  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e" :execution-time 1625   :fn-rv 1}
 {:c-chain [1]   :id 3 :c-id 1   :fn-name "inspector.test.capture-test/simple"   :fn-args (1) :tid 29 :c-tid 34  :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e" :execution-time 42625  :fn-rv 1}
 {:c-chain []    :id 1 :c-id nil :fn-name "inspector.test.capture-test/parallel" :fn-args (1) :tid 34 :c-tid nil :uuid #uuid "4c3bf13a-7899-4202-ade6-cfa0dfc3955e" :execution-time 431833 :fn-rv [0 1]}]

; :fn-rv -> return value. Always check :e when :fn-rv is nil
; :e -> will only be present in case an error was raised. In this case :fn-rv will be set as nil.
; :id -> a unique identifier for each function call.
;        if a function is called twice with exact same arguments the both calls will have different id's assigned to them.
; :c-id -> is the id of the caller function. 
;          c-id = nil implies caller is unknown. 
;          Either because caller function is not modified (bcoz its not part of my-project-vars),
;          Or caller function value if directly being called. Example in case of most handler fns.
; :c-chain -> vector of `:id`. {:id 5 :c-chain [1 2 3 4]} => that :if 5 was called by 4 and 4 was called 3 and so on.
; :uuid -> unique id to identify all the fns (even if some of them ran in different threads) which ran because of call to a top level function.
;          useful when using Omnipresent debug mode.

Ominpresent debug

Start Streaming

(defn export-fn 
  [{:keys [:fn-name :fn-args :fn-rv :id :tid :c-id :c-tid :c-chain :uuid :execution-time :e] :as data}]
  ; send to elasticsearch
  ; or log it
  )
  
; export-fn will be called every time a function execution completes
(i/stream-raw my-vars export-fn)

To skip modifying a function either remove it's var from my-vars or add metadata :inspector-skip.

(defn ^:inspector-skip foo
  [args]
  :body)

Restore vars to original value

(inspector.core/restore-original-value my-vars)

How inspector work?

In clojure a function's name is a symbol. The symbol maps to a var which has a reference to value. Think of value as the actual function which will run when you do (function-name arg1 arg2).

The idea is to change the reference present in var to point to a new value (or new function). This new value (or new function) will wrap the original value (or function) with additional code.

Inspector provides a structured way to modify a lot of values(functions) at once in this way.

Todo

• finally standardise public api
• refactor capture.clj to use stream.clj
• complete tests
• function to stringify function arguments, such as atom, object, ...
• simplify inspector.inspector for printing call hierarchy

License

This program and the accompanying materials are made available under the terms of the Eclipse Public License 2.0 which is available at http://www.eclipse.org/legal/epl-2.0.

This Source Code may also be made available under the following Secondary Licenses when the conditions for such availability set forth in the Eclipse Public License, v. 2.0 are satisfied: GNU General Public License as published by the Free Software Foundation, either version 2 of the License, or (at your option) any later version, with the GNU Classpath Exception which is available at https://www.gnu.org/software/classpath/license.html.