Skip to content

Commit 42bb830

Browse files
golowanowgolowanow
committed
test-case: latency-metrics: introduce latency tests
Introduce latency tests using `JACK` Audio Connection Kit: run `jackd` audio service, connect ports with loopback and run `jack_iodelay` to collect latency measurements, detect xrun-s, calculate and save statistics into a json report file. Signed-off-by: Dmitrii Golovanov <dmitrii.golovanov@intel.com>
1 parent fdd7ae4 commit 42bb830

File tree

5 files changed

+286
-1
lines changed

5 files changed

+286
-1
lines changed

‎case-lib/jack_iodelay_metrics.awk‎

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
#!/usr/bin/gawk -f
2+
3+
# SPDX-License-Identifier: BSD-3-Clause
4+
# Copyright(c) 2025 Intel Corporation. All rights reserved.
5+
6+
# Process `jack_iodelay` output to count XRun's, extract latency measurements,
7+
# and calculate some general statistics: min, max, avg, stddev.
8+
# The resulting output is a json dictionary.
9+
10+
@include "lib.awk"
11+
12+
/^[ ]*[0-9.]+ frames[ ]+[0-9.]+ ms total roundtrip latency/ {
13+
sum_frames+=$1
14+
sum_ms+=$3
15+
latency_frames[NR]=$1
16+
latency_ms[NR]=$3
17+
}
18+
19+
/JackEngine::XRun: client = jack_delay/ {
20+
xrun_cnt+=1
21+
}
22+
23+
END {
24+
if (length(latency_frames) !=0 && length(latency_ms) != 0) {
25+
printf("\"metrics\":[")
26+
printf("{\"name\":\"roundtrip latency\", ")
27+
printf("\"probes\":%d, ", length(latency_frames))
28+
printf("\"xruns\":%d, ", xrun_cnt)
29+
printf("\"avg_frames\":%0.3f, ", (length(latency_frames) ? sum(latency_frames) / length(latency_frames) : 0))
30+
printf("\"min_frames\":%0.3f, \"max_frames\":%0.3f, ", min(latency_frames), max(latency_frames))
31+
printf("\"avg_ms\":%0.3f, ", (length(latency_ms) ? sum(latency_ms) / length(latency_ms) : 0))
32+
printf("\"min_ms\":%0.3f, \"max_ms\":%0.3f, ", min(latency_ms), max(latency_ms))
33+
printf("\"stdev_frames\":%0.6f, \"stdev_ms\":%0.6f }", stddev(latency_frames), stddev(latency_ms))
34+
printf("]")
35+
fflush()
36+
}
37+
}

‎case-lib/lib.awk‎

Lines changed: 55 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,55 @@
1+
#!/usr/bin/gawk -f
2+
3+
# SPDX-License-Identifier: BSD-3-Clause
4+
# Copyright(c) 2025 Intel Corporation. All rights reserved.
5+
6+
# A library of functions to re-use in AWK scripts.
7+
8+
function min(in_array, min_value,idx)
9+
{
10+
min_value = "N/A"
11+
if (! isarray(in_array) || length(in_array) == 0) return min_value
12+
for(idx in in_array) {
13+
if (min_value == "N/A" || in_array[idx] < min_value) {
14+
min_value = in_array[idx]
15+
}
16+
}
17+
return min_value
18+
}
19+
20+
function max(in_array, max_value,idx)
21+
{
22+
max_value = "N/A"
23+
if (! isarray(in_array) || length(in_array) == 0) return max_value
24+
for(idx in in_array) {
25+
if (max_value == "N/A" || in_array[idx] > max_value) {
26+
max_value = in_array[idx]
27+
}
28+
}
29+
return max_value
30+
}
31+
32+
function sum(in_array, sum_items,idx)
33+
{
34+
if (! isarray(in_array) || length(in_array) == 0) return 0
35+
sum_items=0
36+
for(idx in in_array) {
37+
sum_items += in_array[idx]
38+
}
39+
return sum_items
40+
}
41+
42+
function stddev(in_array, sum_items,cnt_items,idx,avg,dev)
43+
{
44+
if (! isarray(in_array) || length(in_array) == 0) return -1
45+
sum_items=0
46+
cnt_items=0
47+
for(idx in in_array) {
48+
sum_items += in_array[idx]
49+
cnt_items += 1
50+
}
51+
avg = sum_items / cnt_items
52+
dev = 0
53+
for(idx in in_array) dev += (in_array[idx] - avg)^2
54+
return sqrt(dev/(cnt_items - 1))
55+
}

‎case-lib/opt.sh‎

Lines changed: 11 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,7 @@
11
#!/bin/bash
22

33
# SPDX-License-Identifier: BSD-3-Clause
4-
# Copyright(c) 2021 Intel Corporation. All rights reserved.
4+
# Copyright(c) 2021-2025 Intel Corporation. All rights reserved.
55

66
# These four arrays are used to define script options, and they should
77
# be indexed by a character [a-zA-Z], which is the option short name.
@@ -26,6 +26,16 @@ add_common_options()
2626
OPT_DESC['h']='show help information'
2727
}
2828

29+
# Convert options to a json dictionary.
30+
options2json()
31+
{
32+
local items_=()
33+
for idx_ in "${!OPT_NAME[@]}" ; do
34+
items_+=("\"${OPT_NAME[$idx_]}\":\"${OPT_VAL[$idx_]}\"")
35+
done
36+
echo "$(IFS=',' ; printf "%s" "${items_[*]}")"
37+
}
38+
2939
# validate command line options, override default option value,
3040
# and dump help
3141
func_opt_parse_option()

‎env-check.sh‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -81,11 +81,18 @@ main "$@"
8181

8282
out_str="" check_res=0
8383
printf "Checking for some OS packages:\t\t"
84+
func_check_pkg gawk
8485
func_check_pkg expect
8586
func_check_pkg aplay
8687
func_check_pkg sox
8788
func_check_pkg tinycap
8889
func_check_pkg tinyplay
90+
# JACK Audio Connection Kit
91+
func_check_pkg jackd
92+
func_check_pkg jack_iodelay
93+
func_check_pkg jack_lsp
94+
func_check_pkg jack_connect
95+
#
8996
func_check_pkg python3
9097
# jq is command-line json parser
9198
func_check_pkg jq

‎test-case/latency-metrics.sh‎

Lines changed: 176 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,176 @@
1+
#!/bin/bash
2+
3+
# SPDX-License-Identifier: BSD-3-Clause
4+
# Copyright(c) 2025 Intel Corporation. All rights reserved.
5+
6+
##
7+
## Case Name: latency baseline statistics collection on a signal path
8+
##
9+
## Preconditions:
10+
## - JACK Audio Connection Kit is installed.
11+
## - loopback connection to measure latency over its signal path.
12+
##
13+
## Description:
14+
## Run `jackd` audio server; execute `jack_iodelay` with its in/out ports
15+
## connected to the loopback-ed ports and give it some time ot collect
16+
## latency measurements (on each 0.5 sec.)
17+
##
18+
## Case step:
19+
## 1. Probe to start `jackd` with parameters given and read configuration.
20+
## 2. Start `jackd` again for latency measurements.
21+
## 3. Start `jack_iodelay` which awaits for its ports connected to loopback.
22+
## 4. Connect `jack_iodelay` ports to signal path ports with the loopback.
23+
## 5. Wait for the period given to collect enough latency measurements.
24+
## 6. Calculate latency statistics and save into a JSON file.
25+
##
26+
## Expect result:
27+
## Latency statistics collected and saved in `test_result.json` file.
28+
## Exit status 0.
29+
##
30+
31+
TESTDIR=$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)
32+
TESTLIB="${TESTDIR}/case-lib"
33+
34+
# shellcheck source=case-lib/lib.sh
35+
source "${TESTLIB}/lib.sh"
36+
37+
OPT_NAME['R']='run-period' OPT_DESC['R']='Time period (in seconds) to measure latency.'
38+
OPT_HAS_ARG['R']=1 OPT_VAL['R']="30"
39+
40+
OPT_NAME['d']='device' OPT_DESC['d']='ALSA pcm device to use by JACK'
41+
OPT_HAS_ARG['d']=1 OPT_VAL['d']="hw:0"
42+
43+
OPT_NAME['r']='rate' OPT_DESC['r']='Sample rate to try latency with'
44+
OPT_HAS_ARG['r']=1 OPT_VAL['r']=48000
45+
46+
OPT_NAME['S']='shorts' OPT_DESC['S']='Try to use 16-bit samples instead of 32-bit, if possible.'
47+
OPT_HAS_ARG['S']=0 OPT_VAL['S']=0
48+
49+
OPT_NAME['p']='port_p' OPT_DESC['p']='Jack playback port with loopback. Example: system:playback_1'
50+
OPT_HAS_ARG['p']=1 OPT_VAL['p']=''
51+
52+
OPT_NAME['c']='port_c' OPT_DESC['c']='Jack capture port with loopback. Example: system:capture_1'
53+
OPT_HAS_ARG['c']=1 OPT_VAL['c']=''
54+
55+
OPT_NAME['s']='sof-logger' OPT_DESC['s']="Open sof-logger trace the data will store at $LOG_ROOT"
56+
OPT_HAS_ARG['s']=0 OPT_VAL['s']=1
57+
58+
OPT_NAME['v']='verbose' OPT_DESC['v']='Verbose logging.'
59+
OPT_HAS_ARG['v']=0 OPT_VAL['v']=0
60+
61+
OPT_NAME['X']='is-xrun-error' OPT_DESC['X']="An 'xrun' detected is the test's error."
62+
OPT_HAS_ARG['X']=0 OPT_VAL['X']=1
63+
64+
func_opt_parse_option "$@"
65+
66+
alsa_device=${OPT_VAL['d']}
67+
alsa_shorts=$([ "${OPT_VAL['S']}" -eq 1 ] && echo '--shorts' || echo '')
68+
port_playback=${OPT_VAL['p']}
69+
port_capture=${OPT_VAL['c']}
70+
rate=${OPT_VAL['r']}
71+
run_period=${OPT_VAL['R']}
72+
run_verbose=$([ "${OPT_VAL['v']}" -eq 1 ] && echo '--verbose' || echo '')
73+
xrun_error=${OPT_VAL['X']}
74+
75+
RESULT_JSON="${LOG_ROOT}/test_result.json"
76+
RUN_PERIOD_MAX="$((run_period + 30))s"
77+
JACKD_TIMEOUT="$((run_period + 15))s"
78+
JACKD_OPTIONS="${run_verbose} --realtime --temporary"
79+
JACKD_BACKEND="alsa"
80+
JACKD_BACKEND_OPTIONS="-d ${alsa_device} -r ${rate} ${alsa_shorts}"
81+
WAIT_JACKD="2s"
82+
IODELAY_TIMEOUT="${run_period}s"
83+
WAIT_IODELAY="2s"
84+
85+
if [ "$port_playback" == "" ] || [ "$port_capture" == "" ]; then
86+
skip_test "No playback or capture Jack port is specified. Skip the test."
87+
fi
88+
89+
check_jackd_configured()
90+
{
91+
dlogi "Check Jack server can be started"
92+
dlogc "jackd ${JACKD_OPTIONS} -d ${JACKD_BACKEND} ${JACKD_BACKEND_OPTIONS}"
93+
# shellcheck disable=SC2086
94+
JACK_NO_AUDIO_RESERVATION=1 timeout --kill-after ${RUN_PERIOD_MAX} ${run_verbose} ${JACKD_TIMEOUT} \
95+
jackd ${JACKD_OPTIONS} -d ${JACKD_BACKEND} ${JACKD_BACKEND_OPTIONS} & jackdPID=$!
96+
97+
sleep ${WAIT_JACKD}
98+
99+
dlogc "jack_lsp"
100+
jack_lsp -AclLpt
101+
102+
dlogi "Waiting Jackd to stop without a client"
103+
wait ${jackdPID}
104+
}
105+
106+
collect_latency_data()
107+
{
108+
dlogi "Start collecting latency data"
109+
dlogc "jackd ${JACKD_OPTIONS} -d ${JACKD_BACKEND} ${JACKD_BACKEND_OPTIONS}"
110+
# shellcheck disable=SC2086
111+
JACK_NO_AUDIO_RESERVATION=1 timeout --kill-after ${RUN_PERIOD_MAX} ${run_verbose} ${JACKD_TIMEOUT} \
112+
jackd ${JACKD_OPTIONS} -d ${JACKD_BACKEND} ${JACKD_BACKEND_OPTIONS} & jackdPID=$!
113+
114+
sleep ${WAIT_JACKD}
115+
dlogc "jack_iodelay"
116+
# shellcheck disable=SC2086
117+
timeout --kill-after ${RUN_PERIOD_MAX} ${run_verbose} ${IODELAY_TIMEOUT} \
118+
stdbuf -oL -eL jack_iodelay | \
119+
tee >(AWKPATH="${TESTLIB}:${AWKPATH}" \
120+
gawk -f "${TESTLIB}/jack_iodelay_metrics.awk" > "${LOG_ROOT}/metrics.json") & iodelayPID="$!"
121+
122+
sleep ${WAIT_IODELAY}
123+
dlogi "jack_connect: ${port_capture} ==>[jack_delay]==> ${port_playback}"
124+
jack_connect jack_delay:out "${port_playback}" && jack_connect jack_delay:in "${port_capture}"
125+
126+
dlogi "Latency data collection"
127+
wait ${jackdPID} ${iodelayPID}
128+
dlogi "Latency data collection completed."
129+
}
130+
131+
compose_report()
132+
{
133+
dlogi "Compose ${RESULT_JSON}"
134+
echo -n "{\"options\":{$(options2json)}," > "${RESULT_JSON}"
135+
cat "${LOG_ROOT}/metrics.json" >> "${RESULT_JSON}" && rm "${LOG_ROOT}/metrics.json"
136+
echo "}" >> "${RESULT_JSON}"
137+
cat "${RESULT_JSON}"
138+
}
139+
140+
check_test_result()
141+
{
142+
dlogi "Check test result in ${RESULT_JSON}"
143+
xruns=$(jq '.metrics[] | select(.xruns > 0).xruns' "${RESULT_JSON}")
144+
if [ -n "$xruns" ] && [ "$xrun_error" ]; then
145+
skip_test "XRuns ${xruns} detected!"
146+
fi
147+
}
148+
149+
main()
150+
{
151+
setup_kernel_check_point
152+
153+
start_test
154+
155+
logger_disabled || func_lib_start_log_collect
156+
157+
# TODO: should we set volume to some pre-defined level (parameterized)
158+
# reset_sof_volume
159+
# set_alsa_settings
160+
161+
check_jackd_configured
162+
163+
collect_latency_data
164+
165+
if [ ! -f "${LOG_ROOT}/metrics.json" ] || [ "$(grep -ce 'metrics' "${LOG_ROOT}/metrics.json")" -lt 1 ]; then
166+
skip_test "No metrics collected"
167+
fi
168+
169+
compose_report
170+
171+
check_test_result
172+
}
173+
174+
{
175+
main "$@"; exit "$?"
176+
}

0 commit comments

Comments
 (0)