Clojure

improvements to exception messages and printing

Details

  • Patch:
    Code
  • Approval:
    Ok

Description

Problems

  • Discussions about "make errors better" often conflate error message, stacktraces, exception data
  • Errors do not clearly indicate in what "phase" of execution they occur (read, compile, macroexpand, evaluation, printing)
  • Errors during macroexpansion do not capture the location in caller source (like read and compile exceptions do), and thus the wrong "location" is reported
  • Clojure prints data into Throwable messages
    • big and ugly
    • outside user control

Principles

  • exception messages should be small strings
    • with the expectation that getMessage will be printed
    • totally controlled by throwing code
    • never print arbitrary data into a message
  • flow data all the way to the edge
    • ex-info & ex-data
    • macroexpand spec errors have a well known format
  • edge printing should be concise by default, configurable by user
    • edge functions like repl-caught respect print and spec bindings
    • concise summary by default
    • all the details when you want

Proposed impl changes

  • stop printing data into message strings
    • ExceptionInfo.toString should list keys, not entire map contents
    • spec.alpha/macroexpand-check should stop including explain-out in message
  • and instead print data (configurably) at the edges repl/pst and main/repl-caught
    • print spec per explain-out
    • print ExceptionInfo keys
  • make CompilerException wrappers special at print time instead of construct time
    • CE message is "CompilerException + file/line"
    • wrapped message is whatever it is
    • edge printers should print both

Discussion

  • what should tools do?
    • leverage the data provided in the exception chain to do whatever they want
    • can use main/repl-caught as a guide
  • what happens to programs that parse exception messages?
    • probably should not do this (Clojure's tests do this but try to minimize it)
    • this proposal changes some wrapper message text, but that was never part of the contract

Patch Status

  • clj-2373-spec-alpha-2.patch - for spec.alpha - don't print explain data into message (callers can do what they want with that)
  • clj-2373-9.patch - for clojure
    • LispReader - made ReaderException line/column fields public so CompilerEx can swipe them
    • Compiler
      • CompilerException now implements IExceptionInfo and works with ex-data
      • Created well-known keys :clojure.error/source,line,column,phase,symbol
      • Created well-known phases :read, :macroexpand, :compile
      • Left existing CompilerException fields, but stored rest into data map
      • Construct new syntax error messages on construction
      • Use toString() to encapsulate combining wrapper and cause into a message
      • On read, spec, macroexpand exceptions, add appropriate wrapping
      • Tweaked existing compiler exception calls as much as possible to record symbol (more could potentially be done here - in some cases we have forms or non-symbol things we could report)
      • Moves "Cause:" down to second line except for macroexpand spec errors
    • Var - expose a method to get the symbol for a var. Many people have requested this functionality via a core function, maybe this is a step in that direction.
    • clojure.main
      • add init-cause (private) function to get initial root (rather than existing weird root-cause)
      • add ex-str function (public) to construct the message to print based on an ex. tools could use this. Embeds some of the phase/printing logic but piggiebacks on CompilerException.toString() for some as well. Handles spec problem ex-data specially - this could be genericized but I have not tried to do that here.
      • change repl-caught to rely on ex-str
      • change main repl code to catch and wrap read and print exceptions to specialize errors
    • test* - in general these are tweaks to test to check the cause message rather than the wrapper message with the help of a new assertion type defined in test-helper

Also see: https://dev.clojure.org/display/design/Exception+handling+update

Screener's Notes

See example-errors.txt attachment for resulting error message examples.

  1. clj-2373-2.patch
    12/Jul/18 12:12 AM
    7 kB
    Alex Miller
  2. clj-2373-3.patch
    11/Aug/18 4:08 PM
    14 kB
    Alex Miller
  3. clj-2373-4.patch
    16/Aug/18 12:39 PM
    27 kB
    Alex Miller
  4. clj-2373-5.patch
    21/Aug/18 10:05 AM
    28 kB
    Alex Miller
  5. clj-2373-6.patch
    22/Aug/18 9:11 AM
    28 kB
    Alex Miller
  6. clj-2373-7.patch
    22/Aug/18 5:01 PM
    27 kB
    Alex Miller
  7. clj-2373-8.patch
    04/Sep/18 2:23 PM
    28 kB
    Stuart Halloway
  8. clj-2373-9.patch
    04/Sep/18 9:05 PM
    29 kB
    Alex Miller
  9. clj-2373-clojure-1.patch
    09/Jul/18 11:59 AM
    5 kB
    Stuart Halloway
  10. clj-2373-spec-alpha-1.patch
    09/Jul/18 11:59 AM
    1 kB
    Stuart Halloway
  11. clj-2373-spec-alpha-2.patch
    16/Aug/18 12:16 PM
    2 kB
    Alex Miller
  12. example-errors.txt
    05/Sep/18 10:40 AM
    2 kB
    Alex Miller
  13. example-errors-1.9.txt
    28/Aug/18 7:14 PM
    2 kB
    Alex Miller

Activity

Hide
Stuart Halloway added a comment - - edited

Output from a REPL session with the "-1" patches: https://gist.github.com/stuarthalloway/d3055d1975b464e8949b854e77a746b1

Show
Stuart Halloway added a comment - - edited Output from a REPL session with the "-1" patches: https://gist.github.com/stuarthalloway/d3055d1975b464e8949b854e77a746b1
Hide
jcr added a comment -

re "many Clojure tests that parse exception strings need to change":

Is it desirable to decouple the error message (as printed to the user) from the error tag/type/kind (for tooling, tests, etc), and make the latter a part of the contract?

Show
jcr added a comment - re "many Clojure tests that parse exception strings need to change": Is it desirable to decouple the error message (as printed to the user) from the error tag/type/kind (for tooling, tests, etc), and make the latter a part of the contract?
Hide
Alexander Yakushev added a comment -

I get the eliding map values from the output is meant to hide the ginormous Spec explanations. But printing only the keys doesn't have much value (pun intended). Is there possibly another solution? I can see two suboptimal ones:

1) Dissoc only the :clojure.spec.alpha/ keywords from the ex-data, Spec being the main offender.
2) Print ex-data with small print-length and print-depth (not sure whether that achieves anything, have to analyze different Spec errors to see if it does).

Show
Alexander Yakushev added a comment - I get the eliding map values from the output is meant to hide the ginormous Spec explanations. But printing only the keys doesn't have much value (pun intended). Is there possibly another solution? I can see two suboptimal ones: 1) Dissoc only the :clojure.spec.alpha/ keywords from the ex-data, Spec being the main offender. 2) Print ex-data with small print-length and print-depth (not sure whether that achieves anything, have to analyze different Spec errors to see if it does).
Hide
Stuart Halloway added a comment -

Thanks for the suggestions!

jcr: That might be desirable, but it is an expansion of scope and is not necessary to solve this problem.

Alexander: This is not just about spec errors, but all ex-data. The data is already present and accessible, and printing the keys gives the user a hint where to look.

Show
Stuart Halloway added a comment - Thanks for the suggestions! jcr: That might be desirable, but it is an expansion of scope and is not necessary to solve this problem. Alexander: This is not just about spec errors, but all ex-data. The data is already present and accessible, and printing the keys gives the user a hint where to look.
Hide
Alex Miller added a comment -

I have dug into the test failures more and there are really two things here...

1) the top level exception messages have changed (and are generally worse for the particular case of a CompilerException with nested init exception, which is not in the example set). I think this bears revisiting for those cases where you might be in a "Java calling Clojure" environment.

2) the message printed to the repl has generally improved, however most of the failing tests are checking exception message as a proxy for what the user sees in a particular error situation via thrown-with-msg?. It would be helpful if "what is printed" could be more easily extracted and if the tests were actually checking that, rather than checking the exception message - I think this better reflects the tests' intent.

I'm working on an updated patch.

Show
Alex Miller added a comment - I have dug into the test failures more and there are really two things here... 1) the top level exception messages have changed (and are generally worse for the particular case of a CompilerException with nested init exception, which is not in the example set). I think this bears revisiting for those cases where you might be in a "Java calling Clojure" environment. 2) the message printed to the repl has generally improved, however most of the failing tests are checking exception message as a proxy for what the user sees in a particular error situation via thrown-with-msg?. It would be helpful if "what is printed" could be more easily extracted and if the tests were actually checking that, rather than checking the exception message - I think this better reflects the tests' intent. I'm working on an updated patch.
Hide
Alex Miller added a comment - - edited

clj-2373-2.patch makes fewer changes in the CompilerException message (tests all continue to pass) but does more in the printing of exception chains in the repl, ignoring the computed message of the wrapper CompilerException completely and focusing more attention on the initial cause (but adding back in the source location info in the CompilerException wrapper if it's available).

user=> (/ 1 0)
ArithmeticException Divide by zero clojure.lang.Numbers.divide (Numbers.java:163)

user=> (throw (ex-info "oops" {:a 1 :b "foo"}))
ExceptionInfo oops clojure.core/ex-info (core.clj:4754)
ex-data keys: [:a :b]

user=> (let [a])
ExceptionInfo Call to clojure.core/let did not conform to spec., compiling:(3:1) clojure.core/ex-info (core.clj:4754)
In: [0] val: () fails spec: :clojure.core.specs.alpha/bindings at: [:args :bindings :init-expr] predicate: any?,  Insufficient input
Show
Alex Miller added a comment - - edited clj-2373-2.patch makes fewer changes in the CompilerException message (tests all continue to pass) but does more in the printing of exception chains in the repl, ignoring the computed message of the wrapper CompilerException completely and focusing more attention on the initial cause (but adding back in the source location info in the CompilerException wrapper if it's available).
user=> (/ 1 0)
ArithmeticException Divide by zero clojure.lang.Numbers.divide (Numbers.java:163)

user=> (throw (ex-info "oops" {:a 1 :b "foo"}))
ExceptionInfo oops clojure.core/ex-info (core.clj:4754)
ex-data keys: [:a :b]

user=> (let [a])
ExceptionInfo Call to clojure.core/let did not conform to spec., compiling:(3:1) clojure.core/ex-info (core.clj:4754)
In: [0] val: () fails spec: :clojure.core.specs.alpha/bindings at: [:args :bindings :init-expr] predicate: any?,  Insufficient input
Hide
Alex Miller added a comment -

Dumped some further design work at https://dev.clojure.org/display/design/Exception+handling+update

Still a WIP, take nothing here as final.

Show
Alex Miller added a comment - Dumped some further design work at https://dev.clojure.org/display/design/Exception+handling+update Still a WIP, take nothing here as final.
Hide
Alex Miller added a comment -

Pushed -3 patch for current state (does not address test failures yet).

Show
Alex Miller added a comment - Pushed -3 patch for current state (does not address test failures yet).
Hide
Phill Wolf added a comment -

A vote for principles of brevity + data-to-the-edge. At the point of throw, code has no idea how many GB of stuff it's including in ex-data and no basis on which to prune it.

Show
Phill Wolf added a comment - A vote for principles of brevity + data-to-the-edge. At the point of throw, code has no idea how many GB of stuff it's including in ex-data and no basis on which to prune it.
Hide
Alex Miller added a comment -

Added -5 patch which removes the macroexpand sub-phase differences and isolates that into the message construction. Also cleans up the repl read exception wrapping to not confusingly wrap in CompilerException.

Show
Alex Miller added a comment - Added -5 patch which removes the macroexpand sub-phase differences and isolates that into the message construction. Also cleans up the repl read exception wrapping to not confusingly wrap in CompilerException.
Hide
Alex Miller added a comment -

-6 patch fixes a couple bugs in printing read errors from source files.

Show
Alex Miller added a comment - -6 patch fixes a couple bugs in printing read errors from source files.
Hide
Alex Miller added a comment -

Added -7 that fixes a double-period on error reading from source file.

Show
Alex Miller added a comment - Added -7 that fixes a double-period on error reading from source file.
Hide
Alex Miller added a comment -

Applied spec patch...

Show
Alex Miller added a comment - Applied spec patch...
Hide
Alex Miller added a comment -

Added -9 patch that fixes test errors in -8 patch

Show
Alex Miller added a comment - Added -9 patch that fixes test errors in -8 patch

People

Vote (21)
Watch (15)

Dates

  • Created:
    Updated:
    Resolved: