clojure.main/report-error pprint problem report and patch drafts

INFO.md

The problem reproduced here occurs when an exception is thrown from user code and reaches clojure.main code responsible for exception reporting. Due to the use of pprint, reporting code can fail, obscuring the error and printing a rather unexpected Java stack trace, which is probably most obscure in case of StackOverflow.

The root cause is potentially buggy ex-info (ex-data with values having broken pprint methods or reference cycles, like overtone/at-at#20) being passed to Throwable->map in clojure.main/report-error. Throwable->map itself calls ex-data in a couple of places.

The "less simple" of the attached patches replaces :clojure.main/trace (the result of Throwable->map) in the report, however an even more advanced one would be able to replace ex-data everywhere in :clojure.main/trace where it can occur.

Being able to narrow down which part of the report caused pprint to fail is an open problem - I haven't looked much into clojure.pprint itself.

In the patch drafts, I haven't considered the intricacies of reporting errors reporting errors - I think a Java stack trace should be enough, otherwise what if we get another nasty ex-data when reporting an error reporting an error reporting an error?

I also haven't checked if it's possible to break pprint for things other than ex-data keys/values - maybe exceptions or even stack frames themselves? Those cases though should be less common.

I was basing on the master branch Clojure, commit 5451cee0 when preparing and testing patch drafts.

nopatch-out.txt

$ java -Dclojure.main.report=stderr -jar clojure.jar repro.clj 
Exception in thread "main" java.lang.Exception: another-exception
        at user$eval143$fn__144.invoke(repro.clj:4)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint_map$fn__11123$fn__11125.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map$fn__11123.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map.invokeStatic(dispatch.clj:112)
        at clojure.pprint$pprint_map.invoke(dispatch.clj:106)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint_map$fn__11123$fn__11125.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map$fn__11123.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map.invokeStatic(dispatch.clj:112)
        at clojure.pprint$pprint_map.invoke(dispatch.clj:106)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint_vector$fn__11108.invoke(dispatch.clj:95)
        at clojure.pprint$pprint_vector.invokeStatic(dispatch.clj:94)
        at clojure.pprint$pprint_vector.invoke(dispatch.clj:92)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint_map$fn__11123$fn__11125.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map$fn__11123.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map.invokeStatic(dispatch.clj:112)
        at clojure.pprint$pprint_map.invoke(dispatch.clj:106)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint_map$fn__11123$fn__11125.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map$fn__11123.invoke(dispatch.clj:113)
        at clojure.pprint$pprint_map.invokeStatic(dispatch.clj:112)
        at clojure.pprint$pprint_map.invoke(dispatch.clj:106)
        at clojure.lang.MultiFn.invoke(MultiFn.java:229)
        at clojure.pprint$write_out.invokeStatic(pprint_base.clj:194)
        at clojure.pprint$pprint$fn__10364.invoke(pprint_base.clj:249)
        at clojure.pprint$pprint.invokeStatic(pprint_base.clj:248)
        at clojure.pprint$pprint.invoke(pprint_base.clj:241)
        at clojure.pprint$pprint.invokeStatic(pprint_base.clj:245)
        at clojure.pprint$pprint.invoke(pprint_base.clj:241)
        at clojure.lang.Var.invoke(Var.java:384)
        at clojure.main$report_error$fn__680$fn__681.invoke(main.clj:603)
        at clojure.main$report_error$fn__680.invoke(main.clj:602)
        at clojure.main$report_error.invokeStatic(main.clj:601)
        at clojure.main$main.invokeStatic(main.clj:666)
        at clojure.main$main.doInvoke(main.clj:616)
        at clojure.lang.RestFn.applyTo(RestFn.java:137)
        at clojure.lang.Var.applyTo(Var.java:705)
        at clojure.main.main(main.java:40)

patch-less-simple-out.txt

$ java -Dclojure.main.report=stderr -jar clojure.jar repro.clj
{:clojure.main/message
 "Syntax error (ExceptionInfo) compiling at (repro.clj:11:1).\nAAA\n",
 :clojure.main/triage
 {:clojure.error/phase :compile-syntax-check,
  :clojure.error/line 11,
  :clojure.error/column 1,
  :clojure.error/source "repro.clj",
  :clojure.error/path "repro.clj",
  :clojure.error/class clojure.lang.ExceptionInfo,
  :clojure.error/cause "AAA"},
 :clojure.main/trace
 "Report pretty-printing failed, suspecting bug in pprint method implementation: java.lang.Exception: another-exception"}

Syntax error (ExceptionInfo) compiling at (repro.clj:11:1).
AAA

patch-less-simple.diff

diff --git a/src/clj/clojure/main.clj b/src/clj/clojure/main.clj
index e769ee56..b08b10c0 100644
--- a/src/clj/clojure/main.clj
+++ b/src/clj/clojure/main.clj
@@ -598,9 +598,17 @@ java -cp clojure.jar clojure.main -i init.clj script.clj args...")
                    :clojure.main/message message
                    :clojure.main/triage triage
                    :clojure.main/trace trace)
-          report-str (with-out-str
-                       (binding [*print-namespace-maps* false]
-                         ((requiring-resolve 'clojure.pprint/pprint) report)))
+          pprint-report (fn [report]
+                          (with-out-str
+                            (binding [*print-namespace-maps* false]
+                              ((requiring-resolve 'clojure.pprint/pprint) report))))
+          report-str (try
+                       (pprint-report report)
+                       (catch Throwable t
+                         (pprint-report
+                           (assoc report :clojure.main/trace
+                                  (str "Report pretty-printing failed, suspecting bug in pprint method implementation: "
+                                       t)))))
           err-path (when (= target "file")
                      (try
                        (let [f (.toFile (Files/createTempFile "clojure-" ".edn" (into-array FileAttribute [])))]

patch-simple-out.txt

$ java -Dclojure.main.report=stderr -jar clojure.jar repro.clj
Report pretty-printing failed, suspecting bug in pprint method implementation: java.lang.Exception: another-exception
Syntax error (ExceptionInfo) compiling at (repro.clj:11:1).
AAA

patch-simple.diff

diff --git a/src/clj/clojure/main.clj b/src/clj/clojure/main.clj
index e769ee56..2514b9ec 100644
--- a/src/clj/clojure/main.clj
+++ b/src/clj/clojure/main.clj
@@ -598,9 +598,12 @@ java -cp clojure.jar clojure.main -i init.clj script.clj args...")
                    :clojure.main/message message
                    :clojure.main/triage triage
                    :clojure.main/trace trace)
-          report-str (with-out-str
-                       (binding [*print-namespace-maps* false]
-                         ((requiring-resolve 'clojure.pprint/pprint) report)))
+          report-str (try (with-out-str
+                            (binding [*print-namespace-maps* false]
+                              ((requiring-resolve 'clojure.pprint/pprint) report)))
+                          (catch Throwable t
+                            (str "Report pretty-printing failed, suspecting bug in pprint method implementation: "
+                                 t)))
           err-path (when (= target "file")
                      (try
                        (let [f (.toFile (Files/createTempFile "clojure-" ".edn" (into-array FileAttribute [])))]

repro.clj

; To run: $ java -Dclojure.main.report=stderr -jar clojure.jar repro.clj 

(require 'clojure.pprint)

(deftype PprintThrows [])
(defmethod clojure.pprint/simple-dispatch PprintThrows [obj]
  (throw (Exception. "another-exception")))

(deftype PprintStackOverflow [])
(defmethod clojure.pprint/simple-dispatch PprintStackOverflow [obj]
  (clojure.pprint/pprint obj))

; Choose one.
;(throw (ex-info "AAA" {:d "Normal ex info"}))
(throw (ex-info "AAA" {:d (PprintThrows.)}))
;(throw (ex-info "AAA" {:d (PprintStackOverflow.)}))