Skip to content

Commit

Permalink
Print more context for complex test conditions (#46138)
Browse files Browse the repository at this point in the history
On some failures, e.g. in the cmdlineargs failure in [1],
printing the failing expression doesn't give us very much
information, because what we're doing is just testing a
small part of a larger structure, but to really diagnose
the failure, we'd really want to see the whole structure
(in this case the stderr output, not just the failure bool).

This introduces an additional `@testset` feature that lets
failures optionally include a context variable that gets printed
on failure. Example:
```
julia> @testset let v=(1,2,3)
           @test v[1] == 1
           @test v[2] == 3
       end
Test Failed at REPL[8]:3
  Expression: v[2] == 3
   Evaluated: 2 == 3
     Context: v = (1, 2, 3)
ERROR: There was an error during testing
```

The syntax here is `@testset let`, which was previously unused.
The testset is transparent and failures/successes are passed
through directly to the parent testset. In particular, using
this kind of testset does not cause additional nesting in
the default testset print.

[1] https://buildkite.com/julialang/julia-master/builds/14160#01822311-84f0-467a-a8af-a5d751f2c6ab/448-728
  • Loading branch information
Keno authored Jul 26, 2022
1 parent 5d2e24f commit ff1b563
Show file tree
Hide file tree
Showing 4 changed files with 126 additions and 28 deletions.
122 changes: 111 additions & 11 deletions stdlib/Test/src/Test.jl
Original file line number Diff line number Diff line change
Expand Up @@ -118,18 +118,24 @@ struct Fail <: Result
orig_expr::String
data::Union{Nothing, String}
value::String
context::Union{Nothing, String}
source::LineNumberNode
message_only::Bool
function Fail(test_type::Symbol, orig_expr, data, value, source::LineNumberNode, message_only::Bool=false)
function Fail(test_type::Symbol, orig_expr, data, value, context, source::LineNumberNode, message_only::Bool)
return new(test_type,
string(orig_expr),
data === nothing ? nothing : string(data),
string(isa(data, Type) ? typeof(value) : value),
context,
source,
message_only)
end
end

# Deprecated fallback constructor without `context` argument (added in Julia 1.9). Remove in Julia 2.0.
Fail(test_type::Symbol, orig_expr, data, value, source::LineNumberNode, message_only::Bool=false) =
Fail(test_type, orig_expr, data, value, nothing, source, message_only)

function Base.show(io::IO, t::Fail)
printstyled(io, "Test Failed"; bold=true, color=Base.error_color())
print(io, " at ")
Expand All @@ -149,10 +155,15 @@ function Base.show(io::IO, t::Fail)
# An exception was expected, but no exception was thrown
print(io, "\n Expected: ", data)
print(io, "\n No exception thrown")
elseif t.test_type === :test && data !== nothing
# The test was an expression, so display the term-by-term
# evaluated version as well
print(io, "\n Evaluated: ", data)
elseif t.test_type === :test
if data !== nothing
# The test was an expression, so display the term-by-term
# evaluated version as well
print(io, "\n Evaluated: ", data)
end
if t.context !== nothing
print(io, "\n Context: ", t.context)
end
end
end

Expand Down Expand Up @@ -643,7 +654,7 @@ function do_test(result::ExecutionResult, orig_expr)
testres = if isa(value, Bool)
# a true value Passes
value ? Pass(:test, orig_expr, result.data, value, result.source) :
Fail(:test, orig_expr, result.data, value, result.source)
Fail(:test, orig_expr, result.data, value, nothing, result.source, false)
else
# If the result is non-Boolean, this counts as an Error
Error(:test_nonbool, orig_expr, value, nothing, result.source)
Expand Down Expand Up @@ -773,10 +784,10 @@ function do_test_throws(result::ExecutionResult, orig_expr, extype)
if success
testres = Pass(:test_throws, orig_expr, extype, exc, result.source, message_only)
else
testres = Fail(:test_throws_wrong, orig_expr, extype, exc, result.source, message_only)
testres = Fail(:test_throws_wrong, orig_expr, extype, exc, nothing, result.source, message_only)
end
else
testres = Fail(:test_throws_nothing, orig_expr, extype, nothing, result.source)
testres = Fail(:test_throws_nothing, orig_expr, extype, nothing, nothing, result.source, false)
end
record(get_testset(), testres)
end
Expand Down Expand Up @@ -952,6 +963,30 @@ finish(ts::FallbackTestSet) = ts

#-----------------------------------------------------------------------

"""
ContextTestSet
Passes test failures through to the parent test set, while adding information
about a context object that is being tested.
"""
struct ContextTestSet <: AbstractTestSet
parent_ts::AbstractTestSet
context_sym::Symbol
context::Any
end

function ContextTestSet(sym::Symbol, @nospecialize(context))
ContextTestSet(get_testset(), sym, context)
end
record(c::ContextTestSet, t) = record(c.parent_ts, t)
function record(c::ContextTestSet, t::Fail)
context = string(c.context_sym, " = ", c.context)
context = t.context === nothing ? context : string(t.context, "\n ", context)
record(c.parent_ts, Fail(t.test_type, t.orig_expr, t.data, t.value, context, t.source, t.message_only))
end

#-----------------------------------------------------------------------

"""
DefaultTestSet
Expand Down Expand Up @@ -1272,7 +1307,10 @@ end
@testset [CustomTestSet] [option=val ...] ["description \$v, \$w"] for v in (...), w in (...) ... end
@testset [CustomTestSet] [option=val ...] ["description \$v, \$w"] foo()
Starts a new test set, or multiple test sets if a `for` loop is provided.
# With begin/end or function call
When @testset is used, with begin/end or a single function call, the macro
starts a new test set in which to evaulate the given expression.
If no custom testset type is given it defaults to creating a `DefaultTestSet`.
`DefaultTestSet` records all the results and, if there are any `Fail`s or
Expand Down Expand Up @@ -1312,7 +1350,7 @@ reproducibility in case of failure, and to allow seamless
re-arrangements of `@testset`s regardless of their side-effect on the
global RNG state.
# Examples
## Examples
```jldoctest; filter = r"trigonometric identities | 4 4 [0-9\\.]+s"
julia> @testset "trigonometric identities" begin
θ = 2/3*π
Expand All @@ -1324,14 +1362,45 @@ julia> @testset "trigonometric identities" begin
Test Summary: | Pass Total Time
trigonometric identities | 4 4 0.2s
```
# `@testset for`
When `@testset for` is used, the macro starts a new test for each iteration of
the provided loop. The semantics of each test set are otherwise identical to that
of that `begin/end` case (as if used for each loop iteration).
# `@testset let`
When `@testset let` is used, the macro starts a *transparent* test set with
the given object added as a context object to any failing test contained
therein. This is useful when performing a set of related tests on one larger
object and it is desirable to print this larger object when any of the
individual tests fail. Transparent test sets do not introduce additional levels
of nesting in the test set hierarchy and are passed through directly to the
parent test set (with the context object appended to any failing tests.)
!!! compat "Julia 1.9"
`@testeset let` requires at least Julia 1.9.
## Examples
```jldoctest
julia> @testset let logi = log(im)
@test imag(logi) == π/2
@test !iszero(real(logi))
end
Test Failed at none:3
Expression: !(iszero(real(logi)))
Context: logi = 0.0 + 1.5707963267948966im
ERROR: There was an error during testing
```
"""
macro testset(args...)
isempty(args) && error("No arguments to @testset")

tests = args[end]

# Determine if a single block or for-loop style
if !isa(tests,Expr) || (tests.head !== :for && tests.head !== :block && tests.head !== :call)
if !isa(tests,Expr) || (tests.head !== :for && tests.head !== :block && tests.head !== :call && tests.head !== :let)

error("Expected function call, begin/end block or for loop as argument to @testset")
end
Expand All @@ -1340,6 +1409,8 @@ macro testset(args...)

if tests.head === :for
return testset_forloop(args, tests, __source__)
elseif tests.head === :let
return testset_context(args, tests, __source__)
else
return testset_beginend_call(args, tests, __source__)
end
Expand All @@ -1348,6 +1419,35 @@ end
trigger_test_failure_break(@nospecialize(err)) =
ccall(:jl_test_failure_breakpoint, Cvoid, (Any,), err)

"""
Generate the code for an `@testset` with a `let` argument.
"""
function testset_context(args, tests, source)
desc, testsettype, options = parse_testset_args(args[1:end-1])
if desc !== nothing || testsettype !== nothing
# Reserve this syntax if we ever want to allow this, but for now,
# just do the transparent context test set.
error("@testset with a `let` argument cannot be customized")
end

assgn = tests.args[1]
if !isa(assgn, Expr) || assgn.head !== :(=)
error("`@testset let` must have exactly one assignment")
end
assignee = assgn.args[1]

tests.args[2] = quote
$push_testset($(ContextTestSet)($(QuoteNode(assignee)), $assignee; $options...))
try
$(tests.args[2])
finally
$pop_testset()
end
end

return esc(tests)
end

"""
Generate the code for a `@testset` with a function call or `begin`/`end` argument
"""
Expand Down
2 changes: 1 addition & 1 deletion stdlib/Test/src/logging.jl
Original file line number Diff line number Diff line change
Expand Up @@ -153,7 +153,7 @@ function record(ts::DefaultTestSet, t::LogTestFailure)
println()
end
# Hack: convert to `Fail` so that test summarization works correctly
push!(ts.results, Fail(:test, t.orig_expr, t.logs, nothing, t.source))
push!(ts.results, Fail(:test, t.orig_expr, t.logs, nothing, nothing, t.source))
t
end

Expand Down
2 changes: 1 addition & 1 deletion stdlib/Test/test/runtests.jl
Original file line number Diff line number Diff line change
Expand Up @@ -346,7 +346,7 @@ let retval_tests = @testset NoThrowTestSet begin
@test Test.record(ts, pass_mock) isa Test.Pass
error_mock = Test.Error(:test, 1, 2, 3, LineNumberNode(0, "An Error Mock"))
@test Test.record(ts, error_mock) isa Test.Error
fail_mock = Test.Fail(:test, 1, 2, 3, LineNumberNode(0, "A Fail Mock"))
fail_mock = Test.Fail(:test, 1, 2, 3, nothing, LineNumberNode(0, "A Fail Mock"), false)
@test Test.record(ts, fail_mock) isa Test.Fail
broken_mock = Test.Broken(:test, LineNumberNode(0, "A Broken Mock"))
@test Test.record(ts, broken_mock) isa Test.Broken
Expand Down
28 changes: 13 additions & 15 deletions test/cmdlineargs.jl
Original file line number Diff line number Diff line change
Expand Up @@ -67,19 +67,17 @@ let exename = `$(Base.julia_cmd()) --startup-file=no --color=no`
"JULIA_LOAD_PATH" => "",
"JULIA_DEPOT_PATH" => "",
"HOME" => homedir()))
@test v[1] == "false\nREPL: InteractiveUtilstrue\n"
@test v[2]
@test v == ("false\nREPL: InteractiveUtilstrue\n", true)
end
let v = writereadpipeline("println(\"REPL: \", InteractiveUtils)",
setenv(`$exename -i -e 'const InteractiveUtils = 3'`,
"JULIA_LOAD_PATH" => ";;;:::",
"JULIA_DEPOT_PATH" => ";;;:::",
"HOME" => homedir()))
# TODO: ideally, `@which`, etc. would still work, but Julia can't handle `using $InterativeUtils`
@test v[1] == "REPL: 3\n"
@test v[2]
@test v == ("REPL: 3\n", true)
end
let v = readchomperrors(`$exename -i -e '
@testset let v = readchomperrors(`$exename -i -e '
empty!(LOAD_PATH)
@eval Sys STDLIB=mktempdir()
Base.unreference_module(Base.PkgId(Base.UUID(0xb77e0a4c_d291_57a0_90e8_8db25a27a240), "InteractiveUtils"))
Expand All @@ -93,32 +91,32 @@ let exename = `$(Base.julia_cmd()) --startup-file=no --color=no`
real_threads = string(ccall(:jl_cpu_threads, Int32, ()))
for nc in ("0", "-2", "x", "2x", " ", "")
v = readchomperrors(setenv(`$exename -i -E 'Sys.CPU_THREADS'`, "JULIA_CPU_THREADS" => nc, "HOME" => homedir()))
@test v[1]
@test v[2] == real_threads
@test v[3] == "WARNING: couldn't parse `JULIA_CPU_THREADS` environment variable. Defaulting Sys.CPU_THREADS to $real_threads."
@test v == (true, real_threads,
"WARNING: couldn't parse `JULIA_CPU_THREADS` environment variable. Defaulting Sys.CPU_THREADS to $real_threads.")
end
for nc in ("1", " 1 ", " +1 ", " 0x1 ")
v = readchomperrors(setenv(`$exename -i -E 'Sys.CPU_THREADS'`, "JULIA_CPU_THREADS" => nc, "HOME" => homedir()))
@test v[1]
@test v[2] == "1"
@test isempty(v[3])
@testset let v = readchomperrors(setenv(`$exename -i -E 'Sys.CPU_THREADS'`, "JULIA_CPU_THREADS" => nc, "HOME" => homedir()))
@test v[1]
@test v[2] == "1"
@test isempty(v[3])
end
end

let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options", "HOME" => homedir()))
@testset let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options", "HOME" => homedir()))
@test v[1]
@test contains(v[2], r"print-options + = 1")
@test contains(v[2], r"combiner-store-merge-dependence-limit + = 4")
@test contains(v[2], r"enable-tail-merge + = 2")
@test isempty(v[3])
end
let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options -enable-tail-merge=1 -combiner-store-merge-dependence-limit=6", "HOME" => homedir()))
@testset let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options -enable-tail-merge=1 -combiner-store-merge-dependence-limit=6", "HOME" => homedir()))
@test v[1]
@test contains(v[2], r"print-options + = 1")
@test contains(v[2], r"combiner-store-merge-dependence-limit + = 6")
@test contains(v[2], r"enable-tail-merge + = 1")
@test isempty(v[3])
end
let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options -enable-tail-merge=1 -enable-tail-merge=1", "HOME" => homedir()))
@testset let v = readchomperrors(setenv(`$exename -e 0`, "JULIA_LLVM_ARGS" => "-print-options -enable-tail-merge=1 -enable-tail-merge=1", "HOME" => homedir()))
@test !v[1]
@test isempty(v[2])
@test v[3] == "julia: for the --enable-tail-merge option: may only occur zero or one times!"
Expand Down

0 comments on commit ff1b563

Please sign in to comment.