RFC: do not print backtrace for TestSetExceptions and Pkg.test() exception. #19750

KristofferC · 2016-12-29T12:36:22Z

Removes the backtraces that points to internal functions that are running tests when these test runners run as expected.

Difference between master and PR

PR:

Master

tkelman · 2016-12-29T13:12:11Z

Wouldn't it be cleaner to use dispatch on exception type to ignore the backtrace keyword argument for some types? That you could even do in your juliarc, probably.

KristofferC · 2016-12-29T13:23:31Z

Do you mean to add something like

Base.showerror(io::IO, ex::TestSetException, bt) = Base.showerror(io, ex)

?

I don't see why .juliarc.jl is relevant.

KristofferC · 2016-12-30T13:14:39Z

AV seemingly got stuck: https://gist.github.com/KristofferC/33b0f4544ec790e2f8e11a2adcfeaf8a. Close and repoen to restart tests.

tkelman · 2016-12-30T16:45:23Z

test/test.jl

+
+let
+    io = IOBuffer()
+    Base.showerror(io, Test.TestSetException(1,2,3,4,Vector{Union{Base.Test.Error, Base.Test.Fail}}()), backtrace())


unaddressed

tkelman · 2016-12-30T18:53:14Z

In the case of Pkg.test, I think a verbose keyword argument to control this would be better than suppressing it unconditionally. Otherwise it's hard to trace and debug what Pkg.test actually runs.

KristofferC · 2016-12-30T18:55:28Z

The full command that Pkg.test runs is still printed. Only the back trace to some arbitrary location in Pkg.Entry is suppressed.

KristofferC · 2016-12-30T19:53:51Z

Explicitly, this is still printed:

===============================[ ERROR: Testpkg ]===============================

failed process: Process(`/home/kristoffer/Downloads/julia-3c9d75391c/bin/julia -Cx86-64 -J/home/kristoffer/Downloads/julia-3c9d75391c/lib/julia/sys.so --compile=yes --depwarn=yes --check-bounds=yes --code-coverage=none --color=yes --compilecache=yes /home/kristoffer/.julia/v0.5/Testpkg/test/runtests.jl`, ProcessExited(1)) [1]

================================================================================

What information do you want from the backtrace I removed?

KristofferC · 2016-12-31T12:09:33Z

Any objections against this?

tkelman · 2016-12-31T12:14:08Z

What information do you want from the backtrace I removed?

The ability to see not just what Pkg.Test runs, but how it gets there. Maybe not shown by default, but make it possible.

KristofferC · 2016-12-31T12:32:46Z

The fact that an exception is thrown is basically a hack so that the process will exit with non zero status if run in noninteractive mode and being able to catch the exception when running in the REPL. To see how arbitrary function gets called, isn't that what you use debuggers for. My point is that, if a PkgTestException is thrown, it means that Pkg.test() works exactly as it should and just as with any other function that does what it should, we don't randomly print a backtrace for it. If Pkg.test() actually errors for some other reason, then its backtrace will be printed.

tkelman · 2016-12-31T12:38:14Z

Most functions don't throw exceptions in the course of doing what they should - or they intentionally catch them. If throwing an exception is a hack, then suppressing the backtrace just for this specific type of exception is putting yet more hacks on top of it.

KristofferC · 2016-12-31T12:53:28Z

Yes. And it gives a significant boost to user experience. I'm not sure I got your point.

KristofferC · 2016-12-31T13:06:46Z

Consider the case where Pkg.test() is always run in a separate process. The throw in the current code would then instead have been exit(1) and would then not print a backtrace. The current backtrace being printed is hence just an artifact of the implementation detail that Pkg.test() is run in the current process and it would be a bad user experience to exit that process. This PR removes that artifact.

tkelman · 2016-12-31T13:28:06Z

The backtrace is an artifact of using an exception, and our normal handling of exceptions. If you're not treating it the way we treat normal exceptions, because you're arguing that it's not exceptional behavior but expected, then it's control flow. At that point it seems like you mostly want to print a message in red and could return the results instead.

KristofferC · 2016-12-31T13:45:32Z

It is "exit status"-control flow. Doing what you suggest would exit the process with the wrong exit code when Pkg.test() gets run in non interactive mode.

stevengj · 2016-12-31T18:16:35Z

What if a test fails not due to @test <false> but rather due to the test throwing an exception?

KristofferC · 2016-12-31T18:43:50Z

There are three backtraces currently being printed when Pkg.test fails. The one you are concerned about is the first one and that one is not touched in the PR. There is another PR dealing with that one #19751.

KristofferC · 2017-01-02T12:47:23Z

Good to go?

tkelman · 2017-01-02T13:11:03Z

I still don't like the unconditional hiding of information here.

KristofferC · 2017-01-02T13:42:13Z

You are using the word "information" but what is removed here is not any actionable information. It is purely implementation details that accidentally leak to the user during completely normal operation of a function. In fact, for every function that we don't print a backtrace to during normal operations we are "hiding information". And that is a crucial part of delivering a good user experience (which the current one is definitely not).

If someone says they want to see the backtrace to where sin is called, the answer would be to set a breakpoint and print the backtrace in a debugger. We wouldn't add a sin(x; backtrace=false) function, which is what it feels like you are proposing.

Seems we are at an impasse so opinions from more people would be good to hear.

tkelman · 2017-01-02T13:44:56Z

Package tests failing arguably aren't normal operation - there was a failure, and it's worth displaying how and where it happened.

KristofferC · 2017-01-02T14:01:35Z

it's worth displaying how and where it happened.

This is not being touched in this PR. The full command to the process running the tests together with the backtrace in that process is printed.

KristofferC · 2017-01-02T14:06:26Z

If a plumber comes to your house and says that a pipe is broken, would you really ask him about the color of his underwear?

quinnj · 2017-01-02T16:14:19Z

I completely agree with @KristofferC here and this change is a significant improvement. I think we just have to view Pkg.test for what it does: it's running the tests for a package; if those tests fail, what's helpful is a message about what failed and where (in the package itself). In my mind, Pkg.test itself isn't and shouldn't be the thing "failing" here, so we shouldn't see it's backtrace; it DID it's job just by TRYING to run the tests. In my mind, this is the exact purpose for having a try-catch block in the language; you desire some alternate behavior to throwing in the case the tryed code has an error.

tkelman · 2017-01-02T16:21:57Z

In my mind, this is the exact purpose for having a try-catch block in the language; you desire some alternate behavior to throwing in the case the tryed code has an error.

This isn't a try-catch though, it's not alternate behavior. It's throwing an exception but always hiding its particular backtrace because we apparently don't like this piece of information? The thing that caused the exit code to be as desired was an error thrown from inside Pkg.

KristofferC · 2017-01-02T16:33:22Z

How about changing

throw(PkgTestError(join(messages, "and")))

to something like

print_with_color(Base.error_color(), STDOUT, join(messages, "and"))
!Base.isinteractive() && exit(1)

StefanKarpinski · 2017-01-02T16:47:43Z

Is exit(1) ok in this situation because this is being run in a subprocess?

KristofferC · 2017-01-02T16:53:29Z

I am not sure, haven't tried it yet. Just trying to make progress.

KristofferC · 2017-01-02T18:54:44Z

I implemented my last comment and just stop throwing an exception. Worked as expected and gave the wrong exit status for everything I tried it on. @tkelman is this better now since it doesn't "pun" on exception throwing?

KristofferC · 2017-01-02T18:55:38Z

base/client.jl

-        showerror(io, er, bt)
-        println(io)
-    end
+    Base.showerror(IOContext(STDERR, :limit => true), er, bt)


This was left out from #19569

tkelman · 2017-01-02T18:57:32Z

Wouldn't that make Pkg.test in a script un-catchable if it fails? My preference would be for a verbose flag to Pkg.test where you could turn the backtrace back on if you wanted it.

KristofferC · 2017-01-02T19:19:53Z

Removed last commit since being able to catch a failing Pkg.test seems useful. I can't justify adding extra maintenance cost in terms of documentation and code for something that I feel no one will ever use and does not provide relevant information.

StefanKarpinski · 2017-01-03T04:54:00Z

I think we should go ahead with this. If we find that there are situations where we actually miss the omitted information, then we can add an option to show it again.

tkelman · 2017-01-03T09:21:35Z

test/test.jl

@@ -396,6 +396,12 @@ end
 @test_throws ErrorException @testset "$(error())" begin
 end

+let
+    io = IOBuffer()
+    Base.showerror(io, Test.TestSetException(1,2,3,4,Vector{Union{Base.Test.Error, Base.Test.Fail}}()), backtrace())


wrap long lines

KristofferC · 2017-01-03T23:08:13Z

Squashed, fixed some of the colors and updated first post with screenshot comparisons to make it more clear what is being changed.

musm · 2017-01-03T23:10:36Z

@KristofferC why is the macro expansion stuff useful to print in the stack trace as well?

KristofferC · 2017-01-03T23:17:56Z

Not all of them are (the first one shows where the test is executed). The other ones are in the same stackframe because of inlining so not sure how to deal with it.

style fixed

StefanKarpinski · 2017-01-04T17:53:24Z

Appears to not just be the 32-bit failure we've been seeing.

StefanKarpinski · 2017-01-06T16:52:23Z

Now the only failure is the ongoing 32-bit Linux failure.

kshyatt added error handling Handling of exceptions by Julia or the user testsystem The unit testing framework and Test stdlib labels Dec 29, 2016

KristofferC closed this Dec 30, 2016

KristofferC reopened this Dec 30, 2016

KristofferC changed the title ~~RFC: do not print backtrace for TestSetExceptions~~ RFC: do not print backtrace for TestSetExceptions and Pkg.test() exception. Dec 30, 2016

KristofferC force-pushed the kc/testset_bt_noprint branch 3 times, most recently from c1e0125 to bc0da73 Compare December 30, 2016 14:54

tkelman reviewed Dec 30, 2016

View reviewed changes

StefanKarpinski added this to the 0.6.0 milestone Jan 2, 2017

KristofferC force-pushed the kc/testset_bt_noprint branch from 57359b6 to 5b5a226 Compare January 2, 2017 18:52

KristofferC commented Jan 2, 2017

View reviewed changes

tkelman previously requested changes Jan 3, 2017

View reviewed changes

KristofferC force-pushed the kc/testset_bt_noprint branch 2 times, most recently from 61adfd7 to 2bf98f7 Compare January 3, 2017 22:29

no longer print backtraces to internal functions that run tests

fce015b

KristofferC force-pushed the kc/testset_bt_noprint branch from 2bf98f7 to fce015b Compare January 3, 2017 22:57

StefanKarpinski approved these changes Jan 6, 2017

View reviewed changes

StefanKarpinski merged commit fd2a882 into master Jan 6, 2017

StefanKarpinski deleted the kc/testset_bt_noprint branch January 6, 2017 16:53

KristofferC mentioned this pull request Jan 7, 2017

Test failure printing no longer has test file line numbers, and is too verbose #18647

Closed

KristofferC mentioned this pull request Jan 30, 2017

remove duplicate and unecessary information printing in runtests.jl #20279

Closed

tkelman mentioned this pull request Jan 31, 2017

runtests.jl: remove unecessary final call stack when run in script mode #20341

Merged

RFC: do not print backtrace for TestSetExceptions and Pkg.test() exception. #19750

RFC: do not print backtrace for TestSetExceptions and Pkg.test() exception. #19750

Conversation

KristofferC commented Dec 29, 2016 • edited Loading

PR:

Master

tkelman commented Dec 29, 2016

KristofferC commented Dec 29, 2016 • edited Loading

KristofferC commented Dec 30, 2016

tkelman Dec 30, 2016

Choose a reason for hiding this comment

tkelman Jan 3, 2017

Choose a reason for hiding this comment

tkelman commented Dec 30, 2016

KristofferC commented Dec 30, 2016

KristofferC commented Dec 30, 2016 • edited Loading

KristofferC commented Dec 31, 2016

tkelman commented Dec 31, 2016

KristofferC commented Dec 31, 2016

tkelman commented Dec 31, 2016

KristofferC commented Dec 31, 2016

KristofferC commented Dec 31, 2016

tkelman commented Dec 31, 2016

KristofferC commented Dec 31, 2016

stevengj commented Dec 31, 2016

KristofferC commented Dec 31, 2016

KristofferC commented Jan 2, 2017

tkelman commented Jan 2, 2017

KristofferC commented Jan 2, 2017 • edited Loading

tkelman commented Jan 2, 2017 • edited Loading

KristofferC commented Jan 2, 2017 • edited Loading

KristofferC commented Jan 2, 2017

quinnj commented Jan 2, 2017

tkelman commented Jan 2, 2017

KristofferC commented Jan 2, 2017 • edited Loading

StefanKarpinski commented Jan 2, 2017

KristofferC commented Jan 2, 2017

KristofferC commented Jan 2, 2017

KristofferC Jan 2, 2017

Choose a reason for hiding this comment

tkelman commented Jan 2, 2017

KristofferC commented Jan 2, 2017

StefanKarpinski commented Jan 3, 2017

tkelman Jan 3, 2017

Choose a reason for hiding this comment

KristofferC commented Jan 3, 2017 • edited Loading

musm commented Jan 3, 2017 • edited Loading

KristofferC commented Jan 3, 2017 • edited Loading

StefanKarpinski commented Jan 4, 2017

StefanKarpinski commented Jan 6, 2017

KristofferC commented Dec 29, 2016 •

edited

Loading

KristofferC commented Dec 29, 2016 •

edited

Loading

KristofferC commented Dec 30, 2016 •

edited

Loading

KristofferC commented Jan 2, 2017 •

edited

Loading

tkelman commented Jan 2, 2017 •

edited

Loading

KristofferC commented Jan 2, 2017 •

edited

Loading

KristofferC commented Jan 2, 2017 •

edited

Loading

KristofferC commented Jan 3, 2017 •

edited

Loading

musm commented Jan 3, 2017 •

edited

Loading

KristofferC commented Jan 3, 2017 •

edited

Loading