Skip to content
New issue

Have a question about this project? # for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “#”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? # to your account

Record arguments don't get printed #8

Closed
martinklepsch opened this issue Mar 27, 2017 · 10 comments
Closed

Record arguments don't get printed #8

martinklepsch opened this issue Mar 27, 2017 · 10 comments

Comments

@martinklepsch
Copy link

martinklepsch commented Mar 27, 2017

I'm not sure to what degree this is intended or not but I expected records to be printed as with pr-str when they fail a predicate. Instead they are printed like this:

my.namespace.MyRecord@aa4acce8

Obviously this is much less useful than the information that would be provided when passing a map.
I could use with-dynamic-assertion-data to turn the record into a map first but I'm wondering if records should be printed via pr-str by default?

ptaoussanis added a commit that referenced this issue Mar 27, 2017
Before commit, records were printing like `my.namespace.MyRecord@aa4acce8`.

This change also affects printing of lazy seqs, etc.
Note that we're currently just depending on pre-existing *print-length*
value here, so care should be taken with validating infinite lazy seqs.
@ptaoussanis
Copy link
Member

Hey Martin! Thanks for pinging about this, behaviour wasn't intentional.

Just pushed [com.taoensso/truss "1.4.0"] to Clojars.

Please do note that the full value should in any case always be available in the exception data map.

Hope that helps?

@martinklepsch
Copy link
Author

martinklepsch commented Mar 27, 2017 via email

@ptaoussanis
Copy link
Member

No problem :-)

The exception data note is interesting and I wasn't aware of it. Now I
don't remember if the full exception data is printed when printing the
stacktrace.

Depends on your environment, but I believe it should be in most cases.

I'll note that there should also be a lot of other handy stuff in the full exception data that you might want, even if the failing val is fully displayed in the exception message.

@martinklepsch
Copy link
Author

Thanks, I'll look into making better use of these.. :)

Another thing (a bit off topic :o)) which has been bugging me on and off is that Truss catches exceptions and validates them as if they were values this sometimes leads to the situation where I get exceptions like this one?

Invariant violation in my.app:224. Test form (string? (foo)) with failing input: #object[taoensso.truss.impl.WrappedError 0x644c8ff8 "taoensso.truss.impl.WrappedError@644c8ff8"]

I assume this is intentional but given your motivation of using Truss like "salt" shouldn't the bottom-most cause always be the most visible?

@ptaoussanis
Copy link
Member

ptaoussanis commented Apr 9, 2017

Hey Martin!

Truss catches exceptions and validates them as if they were values

Oh, definitely not. So the "WrappedError" that you're seeing is actually just Truss's way of telling you that it couldn't validate the argument because a value for the argument doesn't exist.

Truss will throw an invalidation warning in 3 cases:

  • (pred val) returns falsey, e.g. (have string? 5) ; Simple common case
  • (pred val) throws, e.g. (have pos? "hello") ; The predicate fn throws on val
  • val throws on eval before even being passed to the predicate, e.g. (have pos? (/ 1 0)) ; Your case

All relevant info should be attached to the ex-info data. For example:

(have string? (/ 5 0))

Unhandled clojure.lang.ExceptionInfo
Invariant violation in `taoensso.ensso.scratch:849`. Test form `(string? (/ 5 0))` with failing input: `<undefined>` `val` error:
java.lang.ArithmeticException: Divide by zero
{:*?data* nil,
 :elidable? true,
 :dt #inst "2017-04-09T19:59:27.618-00:00",
 :val undefined/threw-error,
 :ns-str "taoensso.ensso.scratch",
 :val-type undefined/threw-error,
 :?err #error {
    :cause "Divide by zero"
    :via
    [{:type java.lang.ArithmeticException
      :message "Divide by zero"
      :at [clojure.lang.Numbers divide "Numbers.java" 158]}]
      :trace []},
 :*assert* true,
 :?data nil,
 :?line 849,
 :form-str "(string? (/ 5 0))"}

Does that make sense? It's definitely not passing through the exception for validation.

Actually, I'll note that you shouldn't be seeing "WrappedError" at all; it should say something like undefined/threw-error instead (to make the meaning clearer). That might be a bug in the public version of Truss here, will double check quickly!

@ptaoussanis
Copy link
Member

About to push v1.5.0 to GitHub which helps improve these error messages:

(have string? (/ 1 0)) ; =>
Invariant violation in `taoensso.truss:68`. Test form `(pos? (/ 1 0))`
failed against input val `<truss/undefined-val>`. An error was thrown
while evaluating input val: [java.lang.ArithmeticException: Divide by zero].
...

Didn't notice this myself earlier since I mostly ignore the error message string and just look at the data map :-)

@martinklepsch
Copy link
Author

@ptaoussanis Hey Peter, I guess what I meant here are these two behaviors:

  • (pred val) throws, e.g. (have pos? "hello") ; The predicate fn throws on val
  • val throws on eval before even being passed to the predicate, e.g. (have pos? (/ 1 0))

My thinking is that if there's an exception that's "exceptional behavior" and should be ignored by validation logic that would otherwise validate a "normal value" and be returned as is.

I think I understand why you want to catch exceptions and turn them into Invariant Violations though. Adding the failing input val (if possible) to the data map can be helpful.

I'll think about this some more :)

@ptaoussanis
Copy link
Member

My thinking is that if there's an exception that's "exceptional behavior" and should be ignored by validation logic that would otherwise validate a "normal value" and be returned as is.

Could you maybe try rephrase that, not sure I follow? Specifically:

  • What would you expect/like (have pos? "hello") to return?
  • What would you expect/like (have pos? (/ 1 0)) to return?

In both cases I think that the current behaviour is highly desirable.

When we write (have pos? x) what we're saying semantically is: at this point in the program, I'm expecting to have something that satisfies the pos? predicate (i.e. a positive number); if I don't - let me know because something's wrong.

So in both these example cases, Truss is warning us that something is wrong. In the first case, the predicate couldn't be satisfied because it threw. In the second, the predicate couldn't be satisfied because there was no value to pass to it.

So in both cases our assertion about state of the running program failed validation.

(To be clear: in both failure cases, we still attach all of the underlying exception info; i.e. we're not obscuring the underlying causes at all).

All this was intended to correct a major frustration I had/have with Clojure's standard assertions: (assert (pos? "hello")) will throw due to the bad pred/val combo, but won't actually trip the assertion.

If we applied the same handling to Truss, that'd mean that you wouldn't get all the other helpful info that Truss supplies to help you debug - like the input value, line number, evaluated forms, dynamic binding data, etc. You'd just see a cryptic JVM error message in your production logs with no extra context.

Does that make sense?

@martinklepsch
Copy link
Author

martinklepsch commented Apr 10, 2017

Hey Peter, thanks for taking the time to further explain, appreciate it very much.

I'm convinced on the state things regarding (have pos? "best wishes to kim").

Regarding the other case (exception thrown while evaluating input-val)...

My thinking is that if there's an exception that's "exceptional behavior" and should be ignored by validation logic that would otherwise validate a "normal value" and be returned as is.

Sorry about cutting it a bit short here, it was early in the morning haha. What I was referring to is that exceptions can "bubble up" where as regular/normal values are always passed as return value of something to the thing above it. When I validate data I want to validate these types of return values. Exceptions are thrown at some point with the purpose of bubbling up — and while you preserve exception data — even changing an exception message can make debugging harder.

I find at the point where an exception occurred it becomes less relevant that there is a validation failing and more important to best surface the original reason for the exception.

I hope that makes more sense? Either way you probably have more experience and there is sound reasoning behind those choices, it's just something that perplexed me. :)

Feel free to close :)

@ptaoussanis
Copy link
Member

I'm convinced on the state things regarding (have pos? "best wishes to kim").

She sends hers btw :-)

When I validate data I want to validate these types of return values. Exceptions are thrown at some point with the purpose of bubbling up — and while you preserve exception data — even changing an exception message can make debugging harder.

Keep in mind that Truss's influence on the exception message is additive: it adds extra context like the line number, source file, input arguments, etc. It doesn't remove anything, the original exception is attached in full as a cause.

Compare the following two examples showing up in your production logs:

1. Unhandled java.lang.ArithmeticException
   Divide by zero
Unhandled clojure.lang.ExceptionInfo
Invariant violation in `taoensso.ensso.scratch:848`. Test form `(pos? (/ 1 0))` failed
against input val `<truss/undefined-val>`.
An error was thrown while evaluating input val:
[java.lang.ArithmeticException: Divide by zero].

The first example isn't super helpful when it pops up in your production logs on a 60k line codebase :-)

I find at the point where an exception occurred it becomes less relevant that there is a validation failing and more important to best surface the original reason for the exception.

The original reason will always be included, but we're also adding the fact that (in addition) we've got an invariant violation tripped by an unexpected exception. An unexpected exception is by definition unexpected; in other words: our expectations about the program were wrong. In other words: we're experiencing an invariant (expectation) violation :-)

In practice, the motivation is to try make debugging as easy as possible. Clojure's own error messages aren't great for debugging, especially in a large code base - so the extra Truss info can be really helpful in practice.

# for free to join this conversation on GitHub. Already have an account? # to comment
Projects
None yet
Development

No branches or pull requests

2 participants