[#508, #543] Improve error reporting with stack trace

.gitignore

@@ -29,3 +29,4 @@ org_babashka*.h
 /bb.pdb
 /bb.stripped.pdb
 /.calva
+!test-resources/divide_by_zero.jar

CHANGELOG.md

@@ -4,7 +4,7 @@ For a list of breaking changes, check [here](#breaking-changes)
 
 ## Unreleased
 
-<!-- TODO: credits  -->
+Thanks to <TODO> for contributing to this release.
 
 ### New
 
@@ -15,12 +15,14 @@ For a list of breaking changes, check [here](#breaking-changes)
 - Expose more transit vars [#525](https://github.com/borkdude/babashka/issues/525) ([@djblue](https://github.com/djblue))
 - Add support for `clojure.datafy`, `Datafiable` and `Navigable` [#468](https://github.com/borkdude/babashka/issues/468)
 - Add support for building and running uberjars [#536](https://github.com/borkdude/babashka/issues/536)
+- Print locals and stack trace on exception [#543](https://github.com/borkdude/babashka/issues/543)
 
 ### Fixed
 
 - Eval metadata on var created with `defn` [borkdude/sci#36](https://github.com/borkdude/sci/issues/36)
 - Metadata fn on var fails if calling the var itself [borkdude/sci#363](https://github.com/borkdude/sci/issues/363)
 - Allow re-binding of core vars in with-redefs [borkdude/sci#375](https://github.com/borkdude/sci/issues/375)
+- Babashka shows wrong filename when error is from required ns [#508](https://github.com/borkdude/babashka/issues/508)
 - Fix reading resources from jar files [#528](https://github.com/borkdude/babashka/issues/528)
 - Switch from canonical to absolute paths in `:file` field on var metadata
   [#532](https://github.com/borkdude/babashka/issues/532)

deps.edn

@@ -7,7 +7,7 @@
          "resources" "sci/resources"],
  :deps {org.clojure/clojure {:mvn/version "1.10.2-alpha1"},
         org.clojure/tools.reader {:mvn/version "1.3.2"},
-        borkdude/edamame {:mvn/version "0.0.11-alpha.13"},
+        borkdude/edamame {:mvn/version "0.0.11-alpha.14"},
         borkdude/graal.locking {:mvn/version "0.0.2"},
         borkdude/sci.impl.reflector {:mvn/version "0.0.1"}
         org.clojure/core.async {:mvn/version "1.1.587"},

project.clj

@@ -15,7 +15,7 @@
   :resource-paths ["resources" "sci/resources"]
   :dependencies [[org.clojure/clojure "1.10.2-alpha1"]
                  [org.clojure/tools.reader "1.3.2"]
-                 [borkdude/edamame "0.0.11-alpha.13"]
+                 [borkdude/edamame "0.0.11-alpha.14"]
                  [borkdude/graal.locking "0.0.2"]
                  [org.clojure/tools.cli "1.0.194"]
                  [cheshire "5.10.0"]

sci

@@ -1 +1 @@
-Subproject commit f6389378181b24b828566ac5307eca25aadf119e
+Subproject commit 76207b456fa44bd792669c765b38f633e474a9e0

script/test

@@ -9,8 +9,10 @@ fi
 java -version
 
 set -eo pipefail
-BABASHKA_PRELOADS=""
+unset BABASHKA_PRELOADS
-BABASHKA_CLASSPATH=""
+unset BABASHKA_CLASSPATH
+unset BABASHKA_PRELOADS_TEST
+
 echo "running tests part 1"
 lein test "$@"
 
@@ -19,8 +21,13 @@ export BABASHKA_PRELOADS_TEST=true
 echo "running tests part 2"
 lein test :only babashka.main-test/preloads-test
 
+export BABASHKA_PRELOADS='(defn ithrow [] (/ 1 0))'
+export BABASHKA_PRELOADS_TEST=true
+echo "running tests part 3"
+lein test :only babashka.main-test/preloads-file-location-test
+
 export BABASHKA_PRELOADS="(require '[env-ns])"
 export BABASHKA_CLASSPATH_TEST=true
 export BABASHKA_CLASSPATH="test-resources/babashka/src_for_classpath_test/env"
-echo "running tests part 3"
+echo "running tests part 4"
 lein test :only babashka.classpath-test/classpath-env-test

src/babashka/main.clj

@@ -33,6 +33,7 @@
    [hf.depstar.uberjar :as uberjar]
    [sci.addons :as addons]
    [sci.core :as sci]
+   [sci.impl.callstack :as cs]
    [sci.impl.namespaces :as sci-namespaces]
    [sci.impl.unrestrict :refer [*unrestricted*]]
    [sci.impl.vars :as vars])
@@ -402,21 +403,120 @@ If neither -e, -f, or --socket-repl are specified, then the first argument that
   {'java.lang.System/exit exit ;; override exit, so we have more control
    'System/exit exit})
 
-(defn error-handler* [^Exception e verbose?]
+(defn ruler [title]
+  (println (apply str "----- " title " " (repeat (- 80 7 (count title)) \-))))
+
+(defn split-stacktrace [stacktrace verbose?]
+  (if verbose? [stacktrace]
+      (let [stack-count (count stacktrace)]
+        (if (<= stack-count 10)
+          [stacktrace]
+          [(take 5 stacktrace)
+           (drop (- stack-count 5) stacktrace)]))))
+
+(defn print-stacktrace
+  [stacktrace {:keys [:verbose?]}]
+  (let [stacktrace (cs/format-stacktrace stacktrace)
+        segments (split-stacktrace stacktrace verbose?)
+        [fst snd] segments]
+    (run! println fst)
+    (when snd
+      (println "...")
+      (run! println snd))))
+
+(defn error-context [ex opts]
+  (let [{:keys [:file :line :column]} (ex-data ex)]
+    (when file
+      (when-let [content (case file
+                           "<expr>" (:expression opts)
+                           "<preloads>" (:preloads opts)
+                           (let [f (io/file file)]
+                             (or (when (.exists f) (slurp f))
+                                 (and (not (.isAbsolute f))
+                                      (when-let [loader (:loader opts)]
+                                        (:source (cp/getResource loader [file] nil)))))))]
+        (let [matching-line (dec line)
+              start-line (max (- matching-line 4) 0)
+              end-line (+ matching-line 6)
+              [before after] (->>
+                              (clojure.string/split-lines content)
+                              (map-indexed list)
+                              (drop start-line)
+                              (take (- end-line start-line))
+                              (split-at (inc (- matching-line start-line))))
+              snippet-lines (concat before
+                                    [[nil (str (clojure.string/join "" (repeat (dec column) " "))
+                                               (str "^--- " (ex-message ex)))]]
+                                    after)
+              indices (map first snippet-lines)
+              max-size (reduce max 0 (map (comp count str) indices))
+              snippet-lines (map (fn [[idx line]]
+                                   (if idx
+                                     (let [line-number (inc idx)]
+                                       (str (format (str "%" max-size "d: ") line-number) line))
+                                     (str (clojure.string/join (repeat (+ max-size 2) " ")) line)))
+                                 snippet-lines)]
+          (clojure.string/join "\n" snippet-lines))))))
+
+(defn right-pad [s n]
+  (let [n (- n (count s))]
+    (str s (str/join (repeat n " ")))))
+
+(defn print-locals [locals]
+  (let [max-name-length (reduce max 0 (map (comp count str)
+                                           (keys locals)))
+        max-name-length (+ max-name-length 2)]
+    (binding [*print-length* 10
+              *print-level* 2]
+      (doseq [[k v] locals]
+        (println (str (right-pad (str k ": ") max-name-length) v))))))
+
+(defn error-handler* [^Exception e opts]
   (binding [*out* *err*]
     (let [d (ex-data e)
           exit-code (:bb/exit-code d)
-          sci-error? (identical? :sci/error (:type d))
+          sci-error? (isa? (:type d) :sci/error)
           ex-name (when sci-error?
                     (some-> ^Throwable (ex-cause e)
                             .getClass .getName))]
       (if exit-code [nil exit-code]
-          (do (if verbose?
+          (do
-                (print-stack-trace e)
+            (ruler "Error")
-                (println (str (or ex-name
+            (println "Type:    " (or
+                                  ex-name
                                   (.. e getClass getName))
-                              (when-let [m (.getMessage e)]
+                     (when-let [t (:type d)]
-                                (str ": " m)) )))
+                       (str " / " t)))
+            (when-let [m (.getMessage e)]
+              (println (str "Message:  " m)))
+            (let [{:keys [:file :line :column]} d]
+              (when line
+                (println (str "Location: "
+                              (when file (str file ":"))
+                              line ":" column""))))
+            (println)
+            (when-let [ec (when sci-error?
+                            (error-context e opts))]
+              (ruler "Context")
+              (println ec)
+              (println))
+            (when-let [locals (not-empty (:locals d))]
+              (ruler "Locals")
+              (print-locals locals)
+              (println))
+            (when sci-error?
+              (when-let
+                  [st (let [st (with-out-str
+                                 (some->
+                                  d :callstack
+                                  cs/stacktrace
+                                  (print-stacktrace opts)))]
+                        (when-not (str/blank? st) st))]
+                (ruler "Stack trace")
+                (println st)))
+            (when (:verbose? opts)
+              (ruler "Exception")
+              (print-stack-trace e))
               (flush)
               [nil 1])))))
 
@@ -493,6 +593,11 @@ If neither -e, -f, or --socket-repl are specified, then the first argument that
                           (System/getenv "BABASHKA_CLASSPATH"))
             _ (when classpath
                 (add-classpath* classpath))
+            abs-path (when file
+                       (let [abs-path (.getAbsolutePath (io/file file))]
+                         (vars/bindRoot sci/file abs-path)
+                         (System/setProperty "babashka.file" abs-path)
+                         abs-path))
             _ (when jar
                 (add-classpath* jar))
             load-fn (fn [{:keys [:namespace :reload]}]
@@ -507,16 +612,13 @@ If neither -e, -f, or --socket-repl are specified, then the first argument that
                           (let [res (cp/source-for-namespace loader namespace nil)]
                             (when uberscript (swap! uberscript-sources conj (:source res)))
                             res))))
-            _ (when file
-                (let [abs-path (.getAbsolutePath (io/file file))]
-                  (vars/bindRoot sci/file abs-path)
-                  (System/setProperty "babashka.file" abs-path)))
             main (if (and jar (not main))
                    (when-let [res (cp/getResource
                                    (cp/loader jar)
                                    ["META-INF/MANIFEST.MF"] {:url? true})]
                      (cp/main-ns res))
                    main)
+
             ;; TODO: pull more of these values to compile time
             opts {:aliases aliases
                   :namespaces (-> namespaces
@@ -557,16 +659,23 @@ If neither -e, -f, or --socket-repl are specified, then the first argument that
                                  main)] nil]
                   file (try [[(read-file file)] nil]
                             (catch Exception e
-                              (error-handler* e verbose?))))
+                              (error-handler* e {:expression expressions
+                                                 :verbose? verbose?
+                                                 :preloads preloads
+                                                 :loader (:loader @cp-state)}))))
             expression (str/join " " expressions) ;; this might mess with the locations...
             exit-code
             ;; handle preloads
             (if exit-code exit-code
                 (do (when preloads
-                      (try
+                      (sci/binding [sci/file "<preloads>"]
-                        (sci/eval-string* sci-ctx preloads)
+                        (try
-                        (catch Throwable e
+                          (sci/eval-string* sci-ctx preloads)
-                          (error-handler* e verbose?))))
+                          (catch Throwable e
+                            (error-handler* e {:expression expression
+                                               :verbose? verbose?
+                                               :preloads preloads
+                                               :loader (:loader @cp-state)})))))
                     nil))
             exit-code
             (or exit-code
@@ -582,28 +691,33 @@ If neither -e, -f, or --socket-repl are specified, then the first argument that
                        nrepl [(start-nrepl! nrepl sci-ctx) 0]
                        uberjar [nil 0]
                        expressions
-                       (try
+                       (sci/binding [sci/file abs-path]
-                         (loop []
+                         (try
-                           (let [in (read-next *in*)]
+                           (loop []
-                             (if (identical? ::EOF in)
+                             (let [in (read-next *in*)]
-                               [nil 0] ;; done streaming
+                               (if (identical? ::EOF in)
-                               (let [res [(let [res
+                                 [nil 0] ;; done streaming
-                                                (sci/binding [input-var in]
+                                 (let [res [(let [res
-                                                  (sci/eval-string* sci-ctx expression))]
+                                                  (sci/binding [sci/file (or @sci/file "<expr>")
-                                            (when (some? res)
+                                                                input-var in]
-                                              (if-let [pr-f (cond shell-out println
+                                                    (sci/eval-string* sci-ctx expression))]
-                                                                  edn-out prn)]
+                                              (when (some? res)
-                                                (if (coll? res)
+                                                (if-let [pr-f (cond shell-out println
-                                                  (doseq [l res
+                                                                    edn-out prn)]
-                                                          :while (not (pipe-signal-received?))]
+                                                  (if (coll? res)
-                                                    (pr-f l))
+                                                    (doseq [l res
-                                                  (pr-f res))
+                                                            :while (not (pipe-signal-received?))]
-                                                (prn res)))) 0]]
+                                                      (pr-f l))
-                                 (if stream?
+                                                    (pr-f res))
-                                   (recur)
+                                                  (prn res)))) 0]]
-                                   res)))))
+                                   (if stream?
-                         (catch Throwable e
+                                     (recur)
-                           (error-handler* e verbose?)))
+                                     res)))))
+                           (catch Throwable e
+                             (error-handler* e {:expression expression
+                                                :verbose? verbose?
+                                                :preloads preloads
+                                                :loader (:loader @cp-state)}))))
                        uberscript [nil 0]
                        :else [(repl/start-repl! sci-ctx) 0]))
                 1)]

test-resources/babashka/file_location1.clj

@@ -0,0 +1,8 @@
+(ns babashka.file-location1
+  (:require [babashka.classpath :as cp]))
+
+(cp/add-classpath "test-resources")
+
+(require '[babashka.file-location2 :as f2])
+
+(f2/uh-oh)

test-resources/babashka/file_location2.clj

@@ -0,0 +1,7 @@
+(ns babashka.file-location2)
+
+(defn ok []
+  "ok")
+
+(defn uh-oh []
+  (/ 1 0))

test-resources/babashka/file_location_preloads.clj

@@ -0,0 +1,5 @@
+(ns babashka.file-location-preloads)
+
+(require 'user)
+(user/ithrow)
+

test/babashka/error_test.clj

@@ -0,0 +1,66 @@
+(ns babashka.error-test
+  (:require
+   [babashka.test-utils :as tu]
+   [clojure.java.io :as io]
+   [clojure.string :as str]
+   [clojure.test :as t :refer [deftest is]]))
+
+(deftest stacktrace-from-script-test
+  (try (tu/bb nil (.getPath (io/file "test" "babashka" "scripts" "divide_by_zero.bb")))
+       (catch Exception e
+         (let [msg (ex-message e)
+               lines (str/split-lines msg)
+               lines (drop-while #(not (str/includes? % "clojure.core//")) lines)
+               matches [#"clojure\.core/"
+                        #"user/foo .*divide_by_zero.bb:2:3"
+                        #"user/foo .*divide_by_zero.bb:1:1"
+                        #"user/bar .*divide_by_zero.bb:5:3"
+                        #"user/bar .*divide_by_zero.bb:4:1"
+                        #"user .*divide_by_zero.bb:7:1"]]
+           (doseq [[l m] (map vector lines matches)]
+             (is (re-find m l)))))))
+
+(deftest stacktrace-from-expr-test
+  (let [output (try (tu/bb nil "
+(defn foo [] (/ 1 0))
+(foo)")
+                    (catch Exception e (ex-message e)))]
+    (is (str/includes? output "----- Stack trace --------------------------------------------------------------
+clojure.core// - <built-in>
+user/foo       - <expr>:2:14
+user/foo       - <expr>:2:1
+user           - <expr>:3:1"))))
+
+(deftest context-test
+  (let [output (try (tu/bb nil "
+(defn foo [] (/ 1 0))
+(foo)")
+                    (catch Exception e (ex-message e)))]
+    (is (str/includes? output "----- Context ------------------------------------------------------------------
+1: 
+2: (defn foo [] (/ 1 0))
+                ^--- Divide by zero
+3: (foo)"))))
+
+(deftest parse-error-context-test
+  (let [output (try (tu/bb nil "{:a}")
+                    (catch Exception e (ex-message e)))]
+    (is (str/includes? output "----- Context ------------------------------------------------------------------
+1: {:a}
+   ^--- The map literal starting with :a contains 1 form(s)."))))
+
+(deftest jar-error-test
+  (let [output (try (tu/bb nil "-cp" (.getPath (io/file "test-resources" "divide_by_zero.jar")) "-e" "(require 'foo)")
+                    (catch Exception e (ex-message e)))]
+    (is (str/includes? output "----- Error --------------------------------------------------------------------
+Type:     java.lang.ArithmeticException  / :sci/error
+Message:  Divide by zero
+Location: foo.clj:1:10
+
+----- Context ------------------------------------------------------------------
+1: (ns foo) (/ 1 0)
+            ^--- Divide by zero
+
+----- Stack trace --------------------------------------------------------------
+clojure.core// - <built-in>
+foo            - foo.clj:1:10"))))

test/babashka/main_test.clj

@@ -527,6 +527,17 @@
     (is (apply = res))
     (is (str/includes? (first res) ".."))))
 
+(deftest file-location-test
+  (is (thrown-with-msg?
+       Exception #"file_location2.clj"
+       (test-utils/bb nil (.getPath (io/file "test-resources" "babashka" "file_location1.clj"))))))
+
+(deftest preloads-file-location-test
+  (when (System/getenv "BABASHKA_PRELOADS_TEST")
+    (is (thrown-with-msg?
+         Exception #"preloads"
+         (test-utils/bb nil (.getPath (io/file "test-resources" "babashka" "file_location_preloads.clj")))))))
+
 ;;;; Scratch
 
 (comment

test/babashka/scripts/divide_by_zero.bb

@@ -0,0 +1,7 @@
+(defn foo []
+  (/ 1 0))
+
+(defn bar []
+  (foo))
+
+(bar)