Skip to content

Commit 2e6b7ef

Browse files
spythemanspytheman
committed
tools: support VTEST_SHOW_LONGEST_BY_RUNTIME=5 VTEST_SHOW_LONGEST_BY_COMPTIME=5 VTEST_SHOW_LONGEST_BY_TOTALTIME=5 v test . 
1 parent 2d8a1da commit 2e6b7ef

File tree

7 files changed

+130
-2
lines changed

7 files changed

+130
-2
lines changed

‎.github/workflows/freebsd_ci.yml‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,9 @@ jobs:
4646
git config --global --add safe.directory .
4747
gmake
4848
sudo ./v symlink
49+
export VTEST_SHOW_LONGEST_BY_RUNTIME=10
50+
export VTEST_SHOW_LONGEST_BY_COMPTIME=10
51+
export VTEST_SHOW_LONGEST_BY_TOTALTIME=10
4952
export VFLAGS='-cc tcc -no-retry-compilation'
5053
./v run ci/freebsd_ci.vsh all
5154
@@ -72,6 +75,9 @@ jobs:
7275
git config --global --add safe.directory .
7376
gmake
7477
sudo ./v symlink
78+
export VTEST_SHOW_LONGEST_BY_RUNTIME=10
79+
export VTEST_SHOW_LONGEST_BY_COMPTIME=10
80+
export VTEST_SHOW_LONGEST_BY_TOTALTIME=10
7581
export VFLAGS='-cc clang'
7682
./v run ci/freebsd_ci.vsh all
7783
@@ -98,5 +104,8 @@ jobs:
98104
git config --global --add safe.directory .
99105
gmake
100106
sudo ./v symlink
107+
export VTEST_SHOW_LONGEST_BY_RUNTIME=10
108+
export VTEST_SHOW_LONGEST_BY_COMPTIME=10
109+
export VTEST_SHOW_LONGEST_BY_TOTALTIME=10
101110
export VFLAGS='-cc gcc'
102111
./v run ci/freebsd_ci.vsh all

‎.github/workflows/linux_ci.yml‎

Lines changed: 10 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,9 @@ jobs:
2727
timeout-minutes: 121
2828
env:
2929
VFLAGS: -cc tcc -no-retry-compilation
30+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
31+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
32+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
3033
steps:
3134
- uses: actions/checkout@v6
3235
- name: Build v
@@ -81,6 +84,10 @@ jobs:
8184
gcc-linux:
8285
runs-on: ubuntu-24.04
8386
timeout-minutes: 121
87+
env:
88+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
89+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
90+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
8491
steps:
8592
- uses: actions/checkout@v6
8693
- name: Build V
@@ -135,6 +142,9 @@ jobs:
135142
timeout-minutes: 121
136143
env:
137144
VFLAGS: -cc clang
145+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
146+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
147+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
138148
steps:
139149
- uses: actions/checkout@v6
140150
- name: Build V

‎.github/workflows/macos_ci.yml‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -30,6 +30,9 @@ jobs:
3030
timeout-minutes: 121
3131
env:
3232
VFLAGS: -cc clang
33+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
34+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
35+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
3336
steps:
3437
- uses: actions/checkout@v6
3538
- name: Build V

‎.github/workflows/sanitized_ci.yml‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -85,6 +85,9 @@ jobs:
8585
VJOBS: 1
8686
UBSAN_OPTIONS: print_stacktrace=1:halt_on_error=1:print_suppressions=0:suppressions=/home/runner/work/v/v/.github/workflows/run_sanitizers_undefined.suppressions
8787
VNATIVE_SKIP_LIBC_VV: 1
88+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
89+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
90+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
8891
steps:
8992
- uses: actions/checkout@v6
9093
- name: Build V
@@ -115,6 +118,9 @@ jobs:
115118
VJOBS: 1
116119
UBSAN_OPTIONS: print_stacktrace=1:halt_on_error=1:print_suppressions=0:suppressions=/home/runner/work/v/v/.github/workflows/run_sanitizers_undefined.suppressions
117120
VNATIVE_SKIP_LIBC_VV: 1
121+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
122+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
123+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
118124
steps:
119125
- uses: actions/checkout@v6
120126
- name: Build V
@@ -145,6 +151,9 @@ jobs:
145151
ASAN_OPTIONS: detect_leaks=1
146152
LSAN_OPTIONS: max_leaks=1:print_suppressions=0:suppressions=/home/runner/work/v/v/.github/workflows/run_sanitizers_leak.suppressions
147153
VNATIVE_SKIP_LIBC_VV: 1
154+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
155+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
156+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
148157
steps:
149158
- uses: actions/checkout@v6
150159
- name: Build V
@@ -176,6 +185,9 @@ jobs:
176185
VFLAGS: -cc msvc
177186
VJOBS: 1
178187
VNATIVE_SKIP_LIBC_VV: 1
188+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
189+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
190+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
179191
steps:
180192
- uses: actions/checkout@v6
181193
- name: Build
@@ -202,6 +214,9 @@ jobs:
202214
ASAN_OPTIONS: detect_leaks=1
203215
LSAN_OPTIONS: max_leaks=1:print_suppressions=0:suppressions=/home/runner/work/v/v/.github/workflows/run_sanitizers_leak.suppressions
204216
VNATIVE_SKIP_LIBC_VV: 1
217+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
218+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
219+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
205220
steps:
206221
- uses: actions/checkout@v6
207222
- name: Build V
@@ -233,6 +248,9 @@ jobs:
233248
VFLAGS: -cc clang -gc none -cflags -fno-omit-frame-pointer
234249
VJOBS: 1
235250
VNATIVE_SKIP_LIBC_VV: 1
251+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
252+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
253+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
236254
steps:
237255
- uses: actions/checkout@v6
238256
- name: Build V
@@ -265,6 +283,9 @@ jobs:
265283
VJOBS: 1
266284
LSAN_OPTIONS: detect_leaks=0
267285
VNATIVE_SKIP_LIBC_VV: 1
286+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
287+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
288+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
268289
steps:
269290
- uses: actions/checkout@v6
270291
- name: Build V

‎.github/workflows/windows_ci.yml‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,9 @@ jobs:
2929
timeout-minutes: 90
3030
env:
3131
VFLAGS: -cc gcc
32+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
33+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
34+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
3235
steps:
3336
- uses: actions/checkout@v6
3437
- name: Show tool versions
@@ -96,6 +99,9 @@ jobs:
9699
timeout-minutes: 60
97100
env:
98101
VFLAGS: -cc msvc
102+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
103+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
104+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
99105
steps:
100106
- uses: actions/checkout@v6
101107
- name: Build
@@ -142,6 +148,9 @@ jobs:
142148
timeout-minutes: 60
143149
env:
144150
VFLAGS: -cc tcc -no-retry-compilation
151+
VTEST_SHOW_LONGEST_BY_RUNTIME: 20
152+
VTEST_SHOW_LONGEST_BY_COMPTIME: 20
153+
VTEST_SHOW_LONGEST_BY_TOTALTIME: 20
145154
steps:
146155
- uses: actions/checkout@v6
147156
- name: Build with make.bat -tcc

‎cmd/tools/modules/testing/common.v‎

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -26,6 +26,10 @@ pub const show_cmd = os.getenv('VTEST_SHOW_CMD') == '1'
2626

2727
pub const show_start = os.getenv('VTEST_SHOW_START') == '1'
2828

29+
pub const show_longest_by_runtime = os.getenv('VTEST_SHOW_LONGEST_BY_RUNTIME').int()
30+
pub const show_longest_by_comptime = os.getenv('VTEST_SHOW_LONGEST_BY_COMPTIME').int()
31+
pub const show_longest_by_totaltime = os.getenv('VTEST_SHOW_LONGEST_BY_TOTALTIME').int()
32+
2933
pub const hide_skips = os.getenv('VTEST_HIDE_SKIP') == '1'
3034

3135
pub const hide_oks = os.getenv('VTEST_HIDE_OK') == '1'
@@ -432,12 +436,13 @@ fn worker_trunner(mut p pool.PoolProcessor, idx int, thread_id int) voidptr {
432436
if ts.root_relative {
433437
relative_file = relative_file.replace_once(ts.vroot + os.path_separator, '')
434438
}
435-
file := os.real_path(relative_file)
439+
normalised_relative_file := relative_file.replace('\\', '/')
440+
441+
file := abs_path
436442
mtc := MessageThreadContext{
437443
file: file
438444
flow_id: thread_id.str()
439445
}
440-
normalised_relative_file := relative_file.replace('\\', '/')
441446

442447
// Ensure that the generated binaries will be stored in an *unique*, fresh, and per test folder,
443448
// inside the common session temporary folder, used for all the tests.

‎cmd/tools/modules/testing/output_normal.v‎

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -22,16 +22,20 @@ fn get_report_running_period_ms() time.Duration {
2222
// It was extracted by the original non customiseable output implementation directly in cmd/tools/modules/testing/common.v
2323
pub struct NormalReporter {
2424
mut:
25+
vroot string
2526
runtime time.Duration
2627
comptime time.Duration
2728
nfiles int
2829
njobs int
2930
//
3031
running shared map[string]LogMessage
3132
compiling shared map[string]LogMessage
33+
rtimes shared []TaskDuration
34+
ctimes shared []TaskDuration
3235
}
3336

3437
pub fn (mut r NormalReporter) session_start(message string, mut ts TestSession) {
38+
r.vroot = ts.vroot.replace('\\', '/') + '/'
3539
header(message)
3640
r.nfiles = ts.files.len
3741
r.njobs = runtime.nr_jobs()
@@ -74,7 +78,56 @@ fn (r &NormalReporter) report_current_running_and_compiling_status_periodically(
7478
}
7579
}
7680

81+
fn (r &NormalReporter) show_longest(label string, limit int, kind TaskKind) {
82+
if limit <= 0 {
83+
return
84+
}
85+
println('> Longest ${limit} by ${label}:')
86+
mut tasks := []TaskDuration{cap: r.nfiles}
87+
match kind {
88+
.comptime {
89+
rlock r.ctimes {
90+
tasks << r.ctimes
91+
}
92+
}
93+
.runtime {
94+
rlock r.rtimes {
95+
tasks << r.rtimes
96+
}
97+
}
98+
.totaltime {
99+
mut tall := []TaskDuration{}
100+
rlock r.rtimes {
101+
tall << r.rtimes
102+
}
103+
rlock r.ctimes {
104+
tall << r.ctimes
105+
}
106+
mut mall := map[string]TaskDuration{}
107+
for task in tall {
108+
if current := mall[task.path] {
109+
mall[task.path].duration = current.duration + task.duration
110+
continue
111+
}
112+
mall[task.path] = task
113+
}
114+
tasks = mall.values()
115+
}
116+
}
117+
tasks.sort(a.duration > b.duration)
118+
for tidx, task in tasks {
119+
npath := task.path.replace('\\', '/').replace(r.vroot, '')
120+
println(' ${tidx + 1:3} | ${task.duration:10s} | ${npath}')
121+
if tidx + 1 >= limit {
122+
break
123+
}
124+
}
125+
}
126+
77127
pub fn (r &NormalReporter) session_stop(message string, mut ts TestSession) {
128+
r.show_longest('compilation time', show_longest_by_comptime, .comptime)
129+
r.show_longest('run time', show_longest_by_runtime, .runtime)
130+
r.show_longest('total time', show_longest_by_totaltime, .totaltime)
78131
println('${ts.benchmark.total_message(message)} Comptime: ${r.comptime.microseconds() / 1000} ms. Runtime: ${r.runtime.microseconds() / 1000} ms.')
79132
}
80133

@@ -89,11 +142,17 @@ pub fn (mut r NormalReporter) report(index int, message LogMessage) {
89142
}
90143
if message.kind == .compile_end {
91144
r.comptime += message.took
145+
lock r.ctimes {
146+
r.ctimes << TaskDuration{message.file, message.took}
147+
}
92148
lock r.compiling {
93149
r.compiling.delete(message.file)
94150
}
95151
}
96152
if message.kind == .cmd_end {
153+
lock r.rtimes {
154+
r.rtimes << TaskDuration{message.file, message.took}
155+
}
97156
r.runtime += message.took
98157
}
99158
if message.kind == .cmd_begin {
@@ -161,3 +220,15 @@ pub fn (r NormalReporter) list_of_failed_commands(failed_cmds []string) {
161220
}
162221
}
163222
}
223+
224+
enum TaskKind {
225+
comptime
226+
runtime
227+
totaltime
228+
}
229+
230+
struct TaskDuration {
231+
mut:
232+
path string
233+
duration time.Duration
234+
}

0 commit comments

Comments
 (0)