Record arguments don't get printed

martinklepsch commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

That sounds excellent, I'll give it a shot as soon as I get a chance! Thanks Peter!

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... my motivation was to see failing values in logs so maybe that was already the case. 😊

Thanks again and best greetings :) On Mon, 27 Mar 2017 at 14:41, Peter Taoussanis notifications@github.com wrote:

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?

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/ptaoussanis/truss/issues/8#issuecomment-289377309, or mute the thread https://github.com/notifications/unsubscribe-auth/AAF82MKcwnE05kewFPuOXi3Wh5vFuzyQks5rp2gsgaJpZM4MpzUZ .

ptaoussanis commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

@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 commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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.

taoensso / truss

Record arguments don't get printed #8