Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Store the worker id used for each run of a testitem #171

Open
wants to merge 3 commits into
base: main
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 2 additions & 2 deletions src/ReTestItems.jl
Original file line number Diff line number Diff line change
Expand Up @@ -355,7 +355,7 @@ function _runtests_in_current_env(
# we use a single TestSetupModules
ctx.setups_evaled = TestSetupModules()
for (i, testitem) in enumerate(testitems.testitems)
testitem.workerid[] = Libc.getpid()
push!(testitem.workerids, Libc.getpid())
testitem.eval_number[] = i
run_number = 1
max_runs = 1 + max(retries, testitem.retries)
Expand Down Expand Up @@ -527,7 +527,7 @@ function manage_worker(
wait(worker)
worker = robust_start_worker(proj_name, nworker_threads, worker_init_expr, ntestitems)
end
testitem.workerid[] = worker.pid
push!(testitem.workerids, worker.pid)
timeout = something(testitem.timeout, default_timeout)
fut = remote_eval(worker, :(ReTestItems.runtestitem($testitem, GLOBAL_TEST_CONTEXT; test_end_expr=$(QuoteNode(test_end_expr)), verbose_results=$verbose_results, logs=$(QuoteNode(logs)))))
max_runs = 1 + max(retries, testitem.retries)
Expand Down
14 changes: 7 additions & 7 deletions src/log_capture.jl
Original file line number Diff line number Diff line change
Expand Up @@ -133,7 +133,7 @@ end
### Logging and reporting helpers ##########################################################

_on_worker() = " on worker $(Libc.getpid())"
_on_worker(ti::TestItem) = " on worker $(ti.workerid[])"
_on_worker(ti::TestItem, run_number::Int) = " on worker $(ti.workerids[run_number])"
_file_info(ti::Union{TestSetup,TestItem}) = string(relpath(ti.file, ti.project_root), ":", ti.line)
_has_logs(ts::TestSetup) = filesize(logpath(ts)) > 0
# The path might not exist if a testsetup always throws an error and we don't get to actually
Expand Down Expand Up @@ -178,11 +178,11 @@ function print_errors_and_captured_logs(
println(report_iob)
# in :eager mode, the logs were already printed
if errors_first
has_errors && _print_test_errors(report_iob, ts, _on_worker(ti))
has_errors && _print_test_errors(report_iob, ts, _on_worker(ti, run_number))
logs != :eager && _print_captured_logs(report_iob, ti, run_number)
else
logs != :eager && _print_captured_logs(report_iob, ti, run_number)
has_errors && _print_test_errors(report_iob, ts, _on_worker(ti))
has_errors && _print_test_errors(report_iob, ts, _on_worker(ti, run_number))
end
if has_errors || has_logs
# a newline to visually separate the report for the current test item
Expand All @@ -196,13 +196,13 @@ function print_errors_and_captured_logs(
return nothing
end

function _print_captured_logs(io, setup::TestSetup, ti::Union{Nothing,TestItem}=nothing)
function _print_captured_logs(io, setup::TestSetup, ti::Union{Nothing,TestItem}, run_number::Int)
if _has_logs(setup)
ti_info = isnothing(ti) ? "" : " (dependency of $(repr(ti.name)))"
printstyled(io, "Captured logs"; bold=true, color=Base.info_color())
print(io, " for test setup \"$(setup.name)\"$(ti_info) at ")
printstyled(io, _file_info(setup); bold=true, color=:default)
println(io, isnothing(ti) ? _on_worker() : _on_worker(ti))
println(io, isnothing(ti) ? _on_worker() : _on_worker(ti, run_number))
open(logpath(setup), "r") do logstore
write(io, logstore)
end
Expand All @@ -215,14 +215,14 @@ end
# will call this function only if some logs were collected or when called with `verbose_results`.
function _print_captured_logs(io, ti::TestItem, run_number::Int)
for setup in ti.testsetups
_print_captured_logs(io, setup, ti)
_print_captured_logs(io, setup, ti, run_number)
end
has_logs = _has_logs(ti, run_number)
bold_text = has_logs ? "Captured Logs" : "No Captured Logs"
printstyled(io, bold_text; bold=true, color=Base.info_color())
print(io, " for test item $(repr(ti.name)) at ")
printstyled(io, _file_info(ti); bold=true, color=:default)
println(io, _on_worker(ti))
println(io, _on_worker(ti, run_number))
has_logs && open(logpath(ti, run_number), "r") do logstore
write(io, logstore)
end
Expand Down
10 changes: 5 additions & 5 deletions src/macros.jl
Original file line number Diff line number Diff line change
Expand Up @@ -126,21 +126,21 @@ struct TestItem
project_root::String
code::Any
testsetups::Vector{TestSetup} # populated by runtests coordinator
workerid::Base.RefValue{Int} # populated when the test item is scheduled
testsets::Vector{DefaultTestSet} # populated when the test item is finished running
workerids::Vector{Int} # populated each time the test item is scheduled
testsets::Vector{DefaultTestSet} # populated each time the test item is finished running
stats::Vector{PerfStats} # populated each time the test item is finished running
eval_number::Base.RefValue{Int} # to keep track of how many items have been run so far
stats::Vector{PerfStats} # populated when the test item is finished running
scheduled_for_evaluation::ScheduledForEvaluation # to keep track of whether the test item has been scheduled for evaluation
end
function TestItem(number, name, id, tags, default_imports, setups, retries, timeout, skip, file, line, project_root, code)
_id = @something(id, repr(hash(name, hash(relpath(file, project_root)))))
return TestItem(
number, name, _id, tags, default_imports, setups, retries, timeout, skip, file, line, project_root, code,
TestSetup[],
Ref{Int}(0),
Int[],
DefaultTestSet[],
Ref{Int}(0),
PerfStats[],
Ref{Int}(0),
ScheduledForEvaluation(),
)
end
Expand Down
14 changes: 13 additions & 1 deletion test/log_capture.jl
Original file line number Diff line number Diff line change
Expand Up @@ -36,7 +36,10 @@ end
ti = TestItem(Ref(42), "TheTestItem", "ID007", [], false, [], 0, nothing, false, "source/path", 42, ".", nothing)
push!(ti.testsetups, setup1)
push!(ti.testsetups, setup2)
push!(ti.testsets, Test.DefaultTestSet("dummy"))
push!(ti.testsets, Test.DefaultTestSet("dummy1"))
push!(ti.workerids, 98765)
push!(ti.testsets, Test.DefaultTestSet("dummy2"))
push!(ti.workerids, 43210)
setup1.logstore[] = open(ReTestItems.logpath(setup1), "w")
setup2.logstore[] = open(ReTestItems.logpath(setup2), "w")

Expand All @@ -46,6 +49,15 @@ end
ReTestItems.print_errors_and_captured_logs(iob, ti, 1, logs=:batched)
logs = String(take!(iob))
@test contains(logs, " for test item \"TheTestItem\" at ")
@test contains(logs, " on worker 98765")
@test contains(logs, "The test item has logs")

# Test we log the right worker id for the test run
open(io->write(io, "The test item has logs"), ReTestItems.logpath(ti, 2), "w")
ReTestItems.print_errors_and_captured_logs(iob, ti, 2, logs=:batched)
logs = String(take!(iob))
@test contains(logs, " for test item \"TheTestItem\" at ")
@test contains(logs, " on worker 43210")
@test contains(logs, "The test item has logs")

open(io->write(io, "The test item has logs"), ReTestItems.logpath(ti, 1), "w")
Expand Down
Loading