mirrors/v
1
0
Fork 0
mirror of https://github.com/vlang/v.git synced 2025-09-17 00:12:26 +03:00
Code Issues Projects Releases Packages Wiki Activity Actions 13

tests: show compile time and runtime for each _test.v file in separate columns (#20520)

Browse source
This commit is contained in:
Delyan Angelov 2024-01-20 17:38:46 +02:00 • committed by GitHub
parent 629bae469b
commit 6107e0d154
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
8 changed files with 142 additions and 53 deletions
Download patch file Download diff file Expand all files Collapse all files

117
cmd/tools/modules/testing/common.v
View file

@ -56,6 +56,11 @@ fn get_all_processes() []string {
}
}
pub enum ActionMode {
compile
compile_and_run
}
pub struct TestSession {
pub mut:
files []string
@ -77,6 +82,8 @@ pub mut:
failed_cmds shared []string
reporter Reporter = Reporter(NormalReporter{})
hash string // used as part of the name of the temporary directory created for tests, to ease cleanup
//
exec_mode ActionMode = .compile // .compile_and_run only for `v test`
}
pub fn (mut ts TestSession) add_failed_cmd(cmd string) {
@ -137,7 +144,7 @@ pub fn (mut ts TestSession) print_messages() {
// first sent *all events* to the output reporter, so it can then process them however it wants:
ts.reporter.report(ts.nmessage_idx, rmessage)
if rmessage.kind in [.cmd_begin, .cmd_end] {
if rmessage.kind in [.cmd_begin, .cmd_end, .compile_begin, .compile_end] {
// The following events, are sent before the test framework has determined,
// what the full completion status is. They can also be repeated multiple times,
// for tests that are flaky and need repeating.
@ -432,13 +439,20 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
is_vet := ts.vargs.contains('vet')
produces_file_output := !(is_fmt || is_vet)
if relative_file.ends_with('js.v') {
if relative_file.ends_with('.js.v') {
if produces_file_output {
cmd_options << ' -b js'
run_js = true
}
}
if relative_file.ends_with('.c.v') {
if produces_file_output {
cmd_options << ' -b c'
run_js = false
}
}
if relative_file.contains('global') && !is_fmt {
cmd_options << ' -enable-globals'
}
@ -451,6 +465,7 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
flow_id: thread_id.str()
}
normalised_relative_file := relative_file.replace('\\', '/')
// Ensure that the generated binaries will be stored in an *unique*, fresh, and per test folder,
// inside the common session temporary folder, used for all the tests.
// This is done to provide a clean working environment, for each test, that will not contain
@ -467,10 +482,15 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
os.mkdir_all(test_folder_path) or {}
}
fname := os.file_name(file)
// There are test files ending with `_test.v`, `_test.c.v` and `_test.js.v`.
mut fname_without_extension := fname.all_before_last('.v')
if fname_without_extension.ends_with('.c') {
fname_without_extension = fname_without_extension.all_before_last('.c')
}
generated_binary_fname := if os.user_os() == 'windows' && !run_js {
fname.all_before_last('.v') + '.exe'
fname_without_extension + '.exe'
} else {
fname.all_before_last('.v')
fname_without_extension
}
generated_binary_fpath := os.join_path_single(test_folder_path, generated_binary_fname)
if produces_file_output {
@ -479,18 +499,29 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
}
cmd_options << ' -o ${os.quoted_path(generated_binary_fpath)}'
}
cmd := '${os.quoted_path(ts.vexe)} ${cmd_options.join(' ')} ${os.quoted_path(file)}'
defer {
if produces_file_output && ts.rm_binaries {
os.rmdir_all(test_folder_path) or {}
}
}
cmd := '${os.quoted_path(ts.vexe)} -skip-running ${cmd_options.join(' ')} ${os.quoted_path(file)}'
run_cmd := if run_js { 'node ${generated_binary_fpath}' } else { generated_binary_fpath }
ts.benchmark.step()
tls_bench.step()
if relative_file.replace('\\', '/') in ts.skip_files {
ts.benchmark.skip()
tls_bench.skip()
if !testing.hide_skips {
ts.append_message(.skip, tls_bench.step_message_skip(normalised_relative_file),
mtc)
ts.append_message(.skip, tls_bench.step_message_with_label_and_duration(benchmark.b_skip,
normalised_relative_file, 0,
preparation: 1 * time.microsecond
), mtc)
}
return pool.no_result
}
mut compile_cmd_duration := time.Duration(0)
mut cmd_duration := time.Duration(0)
if ts.show_stats {
ts.reporter.divider()
@ -505,7 +536,7 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
}
mut status := res.exit_code
mut cmd_duration := d_cmd.elapsed()
cmd_duration = d_cmd.elapsed()
ts.append_message_with_duration(.cmd_end, '', cmd_duration, mtc)
if status != 0 {
@ -536,40 +567,49 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
goto test_passed_system
}
}
// most probably compiler error
if res.output.contains(': error: ') {
ts.append_message(.cannot_compile, 'Cannot compile file ${file}', mtc)
}
ts.benchmark.fail()
tls_bench.fail()
ts.add_failed_cmd(cmd)
return pool.no_result
} else {
test_passed_system:
ts.benchmark.ok()
tls_bench.ok()
}
} else {
if testing.show_start {
ts.append_message(.info, ' starting ${relative_file} ...',
mtc)
}
ts.append_message(.cmd_begin, cmd, mtc)
d_cmd := time.new_stopwatch()
mut r := os.execute(cmd)
mut cmd_duration := d_cmd.elapsed()
ts.append_message_with_duration(.cmd_end, r.output, cmd_duration, mtc)
if r.exit_code < 0 {
ts.append_message(.compile_begin, cmd, mtc)
compile_d_cmd := time.new_stopwatch()
mut compile_r := os.execute(cmd)
compile_cmd_duration = compile_d_cmd.elapsed()
ts.append_message_with_duration(.compile_end, compile_r.output, compile_cmd_duration,
mtc)
if compile_r.exit_code != 0 {
ts.benchmark.fail()
tls_bench.fail()
ts.append_message_with_duration(.fail, tls_bench.step_message_fail(normalised_relative_file),
cmd_duration, mtc)
ts.append_message_with_duration(.fail, tls_bench.step_message_with_label_and_duration(benchmark.b_fail,
normalised_relative_file, cmd_duration,
preparation: compile_cmd_duration
), cmd_duration, mtc)
ts.add_failed_cmd(cmd)
return pool.no_result
}
tls_bench.step_restart()
ts.benchmark.step_restart()
if ts.exec_mode == .compile {
unsafe {
goto test_passed_execute
}
}
//
ts.append_message(.cmd_begin, run_cmd, mtc)
d_cmd := time.new_stopwatch()
mut r := os.execute(run_cmd)
cmd_duration = d_cmd.elapsed()
ts.append_message_with_duration(.cmd_end, r.output, cmd_duration, mtc)
if r.exit_code != 0 {
details := get_test_details(file)
os.setenv('VTEST_RETRY_MAX', '${details.retry}', true)
@ -578,9 +618,9 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
mtc)
os.setenv('VTEST_RETRY', '${retry}', true)
ts.append_message(.cmd_begin, cmd, mtc)
ts.append_message(.cmd_begin, run_cmd, mtc)
d_cmd_2 := time.new_stopwatch()
r = os.execute(cmd)
r = os.execute(run_cmd)
cmd_duration = d_cmd_2.elapsed()
ts.append_message_with_duration(.cmd_end, r.output, cmd_duration, mtc)
@ -601,21 +641,24 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
ts.benchmark.fail()
tls_bench.fail()
ending_newline := if r.output.ends_with('\n') { '\n' } else { '' }
ts.append_message_with_duration(.fail, tls_bench.step_message_fail('${normalised_relative_file}\n${r.output.trim_space()}${ending_newline}'),
cmd_duration, mtc)
ts.append_message_with_duration(.fail, tls_bench.step_message_with_label_and_duration(benchmark.b_fail,
'${normalised_relative_file}\n${r.output.trim_space()}${ending_newline}',
cmd_duration,
preparation: compile_cmd_duration
), cmd_duration, mtc)
ts.add_failed_cmd(cmd)
} else {
test_passed_execute:
ts.benchmark.ok()
tls_bench.ok()
if !testing.hide_oks {
ts.append_message_with_duration(.ok, tls_bench.step_message_ok(normalised_relative_file),
cmd_duration, mtc)
}
return pool.no_result
}
}
if produces_file_output && ts.rm_binaries {
os.rmdir_all(test_folder_path) or {}
test_passed_system:
test_passed_execute:
ts.benchmark.ok()
tls_bench.ok()
if !testing.hide_oks {
ts.append_message_with_duration(.ok, tls_bench.step_message_with_label_and_duration(benchmark.b_ok,
normalised_relative_file, cmd_duration,
preparation: compile_cmd_duration
), cmd_duration, mtc)
}
return pool.no_result
}

4
cmd/tools/modules/testing/output.v
View file

@ -3,6 +3,8 @@ module testing
import time
pub enum MessageKind {
compile_begin // sent right before *each* _test.v file compilation, the resulting status is not known yet, but the _test.v file itself is
compile_end // sent right after *each* _test.v file compilation, the message contains the output of that compilation
cmd_begin // sent right before *each* _test.v file execution, the resulting status is not known yet, but the _test.v file itself is
cmd_end // sent right after *each* _test.v file execution, the message contains the output of that execution
//
@ -21,7 +23,7 @@ pub:
kind MessageKind // see the MessageKind declaration above
file string // the _test.v file that the message is about
when time.Time // when was the message sent (messages are sent by the execution threads at the *end* of each event)
flow_id string // the messages of each thread, producing LogMessage, will have all the same unique flowid. Messages by other threads will have other flowid. If you use VJOBS=1 to serialise the execution, then all messages will have the same flowid.
flow_id string // the messages of each thread, producing LogMessage, will have all the same unique flow_id. Messages by other threads will have other flow_id. If you use VJOBS=1 to serialise the execution, then all messages will have the same flow_id.
took time.Duration // the duration of the event, that this message describes
message string // the actual message text; the result of the event, that the message describes; most reporters could ignore this, since it could be reconstructed by the other fields
}

14
cmd/tools/modules/testing/output_normal.v
View file

@ -1,5 +1,6 @@
module testing
import time
import term
pub const empty = term.header(' ', ' ')
@ -8,6 +9,9 @@ pub const empty = term.header(' ', ' ')
// It is used by default by `v test .`
// It was extracted by the original non customiseable output implementation directly in cmd/tools/modules/testing/common.v
pub struct NormalReporter {
mut:
runtime time.Duration
comptime time.Duration
}
pub fn (r NormalReporter) session_start(message string, mut ts TestSession) {
@ -15,13 +19,19 @@ pub fn (r NormalReporter) session_start(message string, mut ts TestSession) {
}
pub fn (r NormalReporter) session_stop(message string, mut ts TestSession) {
println(ts.benchmark.total_message(message))
println('${ts.benchmark.total_message(message)} Comptime: ${r.comptime.microseconds() / 1000} ms. Runtime: ${r.runtime.microseconds() / 1000} ms.')
}
// the most general form; it may be useful for other reporters
// in the normal one, it currently does nothing
pub fn (r NormalReporter) report(index int, message LogMessage) {
pub fn (mut r NormalReporter) report(index int, message LogMessage) {
// eprintln('> ${@METHOD} index: $index | message: $message')
if message.kind == .compile_end {
r.comptime += message.took
}
if message.kind == .cmd_end {
r.runtime += message.took
}
}
pub fn (r NormalReporter) report_stop() {

1
cmd/tools/vtest-self.v
View file

@ -352,6 +352,7 @@ fn main() {
}
testing.eheader(title)
mut tsession := testing.new_test_session(cmd_prefix, true)
tsession.exec_mode = .compile_and_run
tsession.files << all_test_files.filter(!it.contains('testdata' + os.path_separator))
tsession.skip_files << skip_test_files

6
cmd/tools/vtest.v
View file

@ -32,9 +32,10 @@ fn main() {
exit(1)
}
backend_pos := args_before.index('-b')
backend := if backend_pos == -1 { '.c' } else { args_before[backend_pos + 1] } // this giant mess because closures are not implemented
backend := if backend_pos == -1 { '.c' } else { args_before[backend_pos + 1] }
mut ts := testing.new_test_session(args_before.join(' '), true)
ts.exec_mode = .compile_and_run
ts.fail_fast = ctx.fail_fast
for targ in args_after {
if os.is_dir(targ) {
@ -152,6 +153,9 @@ fn (mut ctx Context) should_test(path string, backend string) ShouldTestStatus {
if path.ends_with('_test.v') {
return ctx.should_test_when_it_contains_matching_fns(path, backend)
}
if path.ends_with('_test.c.v') {
return ctx.should_test_when_it_contains_matching_fns(path, backend)
}
if path.ends_with('_test.js.v') {
if testing.is_node_present {
return ctx.should_test_when_it_contains_matching_fns(path, backend)