xref: /freebsd/sys/contrib/openzfs/tests/test-runner/include/logapi.shlib (revision 22649d4dba730d46244fd2dff4fd174903c8379f)
1# SPDX-License-Identifier: CDDL-1.0
2#
3# This file and its contents are supplied under the terms of the
4# Common Development and Distribution License ("CDDL"), version 1.0.
5# You may only use this file in accordance with the terms of version
6# 1.0 of the CDDL.
7#
8# A full copy of the text of the CDDL should have accompanied this
9# source.  A copy of the CDDL is also available via the Internet at
10# https://opensource.org/license/CDDL-1.0.
11#
12
13#
14# Copyright 2007 Sun Microsystems, Inc.  All rights reserved.
15# Use is subject to license terms.
16#
17# Copyright (c) 2012, 2020 by Delphix. All rights reserved.
18# Copyright (c) 2025, Klara, Inc.
19#
20
21STF_PASS=0
22STF_FAIL=1
23STF_UNRESOLVED=2
24STF_UNSUPPORTED=4
25STF_UNTESTED=5
26
27# Output an assertion
28#
29# $@ - assertion text
30
31function log_assert
32{
33	_printline ASSERTION: "$@"
34}
35
36# Output a comment
37#
38# $@ - comment text
39
40function log_note
41{
42	_printline NOTE: "$@"
43}
44
45# Execute and print command with status where success equals non-zero result
46#
47# $@ - command to execute
48#
49# return 0 if command fails, otherwise return 1
50
51function log_neg
52{
53	log_neg_expect "" "$@"
54}
55
56# Execute a positive test and exit $STF_FAIL is test fails
57#
58# $@ - command to execute
59
60function log_must
61{
62	log_pos "$@" || log_fail
63}
64
65# Execute a positive test (expecting no stderr) and exit $STF_FAIL
66# if test fails
67# $@ - command to execute
68
69function log_must_nostderr
70{
71	log_pos_nostderr "$@" || log_fail
72}
73
74# Execute a positive test but retry the command on failure if the output
75# matches an expected pattern.  Otherwise behave like log_must and exit
76# $STF_FAIL is test fails.
77#
78# $1 - retry keyword
79# $2 - retry attempts
80# $3-$@ - command to execute
81#
82function log_must_retry
83{
84	typeset logfile="/tmp/log.$$"
85	typeset status=1
86	typeset expect=$1
87	typeset retry=$2
88	typeset delay=1
89	shift 2
90
91	while [[ -e $logfile ]]; do
92		logfile="$logfile.$$"
93	done
94
95	while (( $retry > 0 )); do
96		"$@" 2>$logfile
97		status=$?
98
99		if (( $status == 0 )); then
100			if grep -qEi "internal error|assertion failed" $logfile; then
101				cat $logfile >&2
102				_printerror "$@" "internal error or" \
103					" assertion failure exited $status"
104				status=1
105			else
106				[[ -n $LOGAPI_DEBUG ]] && cat $logfile
107				_printsuccess "$@"
108			fi
109			break
110		else
111			if grep -qi "$expect" $logfile; then
112				cat $logfile >&2
113				_printerror "$@" "Retry in $delay seconds"
114				sleep $delay
115
116				(( retry=retry - 1 ))
117				(( delay=delay * 2 ))
118			else
119				break;
120			fi
121		fi
122	done
123
124	if (( $status != 0 )) ; then
125		cat $logfile >&2
126		_printerror "$@" "exited $status"
127	fi
128
129	_recursive_output $logfile "false"
130	return $status
131}
132
133# Execute a positive test and exit $STF_FAIL is test fails after being
134# retried up to 5 times when the command returns the keyword "busy".
135#
136# $@ - command to execute
137function log_must_busy
138{
139	log_must_retry "busy" 5 "$@" || log_fail
140}
141
142# Execute a negative test and exit $STF_FAIL if test passes
143#
144# $@ - command to execute
145
146function log_mustnot
147{
148	log_neg "$@" || log_fail
149}
150
151# Execute a negative test with keyword expected, and exit
152# $STF_FAIL if test passes
153#
154# $1 - keyword expected
155# $2-$@ - command to execute
156
157function log_mustnot_expect
158{
159	log_neg_expect "$@" || log_fail
160}
161
162# Signal numbers are platform-dependent
163case $(uname) in
164Darwin|FreeBSD)
165	SIGBUS=10
166	SIGSEGV=11
167	;;
168illumos|Linux|*)
169	SIGBUS=7
170	SIGSEGV=11
171	;;
172esac
173EXIT_SUCCESS=0
174EXIT_NOTFOUND=127
175EXIT_SIGNAL=256
176EXIT_SIGBUS=$((EXIT_SIGNAL + SIGBUS))
177EXIT_SIGSEGV=$((EXIT_SIGNAL + SIGSEGV))
178
179# Execute and print command with status where success equals non-zero result
180# or output includes expected keyword
181#
182# $1 - keyword expected
183# $2-$@ - command to execute
184#
185# return 0 if command fails, or the output contains the keyword expected,
186# return 1 otherwise
187
188function log_neg_expect
189{
190	typeset logfile="/tmp/log.$$"
191	typeset ret=1
192	typeset expect=$1
193	shift
194
195	while [[ -e $logfile ]]; do
196		logfile="$logfile.$$"
197	done
198
199	"$@" 2>$logfile
200	typeset status=$?
201
202	#
203	# A command which printed what was expected of it plainly ran, so
204	# its exit status is its own to interpret.  Some commands report a
205	# count there: fio exits with the number of jobs which failed, and
206	# a run of 127 failing jobs is indistinguishable from a missing
207	# binary by status alone.
208	#
209	typeset expect_missing=1
210	if [[ -n $expect ]] && grep -qi "$expect" $logfile; then
211		expect_missing=0
212	fi
213
214	# unexpected status
215	if (( $status == EXIT_SUCCESS )); then
216		 cat $logfile >&2
217		_printerror "$@" "unexpectedly exited $status"
218	# missing binary
219	elif (( $status == EXIT_NOTFOUND && expect_missing )); then
220		cat $logfile >&2
221		_printerror "$@" "unexpectedly exited $status (File not found)"
222	# bus error - core dump
223	elif (( $status == EXIT_SIGBUS )); then
224		cat $logfile >&2
225		_printerror "$@" "unexpectedly exited $status (Bus Error)"
226	# segmentation violation - core dump
227	elif (( $status == EXIT_SIGSEGV )); then
228		cat $logfile >&2
229		_printerror "$@" "unexpectedly exited $status (SEGV)"
230	else
231		if grep -qEi "internal error|assertion failed" $logfile; then
232			cat $logfile >&2
233			_printerror "$@" "internal error or assertion failure" \
234				" exited $status"
235		elif [[ -n $expect ]] ; then
236			if grep -qi "$expect" $logfile; then
237				ret=0
238			else
239				cat $logfile >&2
240				_printerror "$@" "unexpectedly exited $status"
241			fi
242		else
243			ret=0
244		fi
245
246		if (( $ret == 0 )); then
247			[[ -n $LOGAPI_DEBUG ]] && cat $logfile
248			_printsuccess "$@" "exited $status"
249		fi
250	fi
251	_recursive_output $logfile "false"
252	return $ret
253}
254
255# Execute and print command with status where success equals zero result
256#
257# $@ command to execute
258#
259# return command exit status
260
261function log_pos
262{
263	typeset logfile="/tmp/log.$$"
264
265	while [[ -e $logfile ]]; do
266		logfile="$logfile.$$"
267	done
268
269	"$@" 2>$logfile
270	typeset status=$?
271
272	if (( $status != 0 )) ; then
273		cat $logfile >&2
274		_printerror "$@" "exited $status"
275	else
276		if grep -qEi "internal error|assertion failed" $logfile; then
277			cat $logfile >&2
278			_printerror "$@" "internal error or assertion failure" \
279				" exited $status"
280			status=1
281		else
282			[[ -n $LOGAPI_DEBUG ]] && cat $logfile
283			_printsuccess "$@"
284		fi
285	fi
286	_recursive_output $logfile "false"
287	return $status
288}
289
290# Execute and print command with status where success equals zero result
291# and no stderr output
292#
293# $@ command to execute
294#
295# return 0 if command succeeds and no stderr output
296# return 1 othersie
297
298function log_pos_nostderr
299{
300	typeset logfile="/tmp/log.$$"
301
302	while [[ -e $logfile ]]; do
303		logfile="$logfile.$$"
304	done
305
306	"$@" 2>$logfile
307	typeset status=$?
308
309	if (( $status != 0 )) ; then
310		cat $logfile >&2
311		_printerror "$@" "exited $status"
312	else
313		if [ -s "$logfile" ]; then
314			cat $logfile >&2
315			_printerror "$@" "message in stderr" \
316				" exited $status"
317			status=1
318		else
319			[[ -n $LOGAPI_DEBUG ]] && cat $logfile
320			_printsuccess "$@"
321		fi
322	fi
323	_recursive_output $logfile "false"
324	return $status
325}
326
327# Set an exit handler
328#
329# $@ - function(s) to perform on exit
330
331function log_onexit
332{
333	_CLEANUP=("$*")
334}
335
336# Push an exit handler on the cleanup stack
337#
338# $@ - function(s) to perform on exit
339
340function log_onexit_push
341{
342	_CLEANUP+=("$*")
343}
344
345# Pop an exit handler off the cleanup stack
346
347function log_onexit_pop
348{
349	_CLEANUP=("${_CLEANUP[@]:0:${#_CLEANUP[@]}-1}")
350}
351
352#
353# Exit functions
354#
355
356# Perform cleanup and exit $STF_PASS
357#
358# $@ - message text
359
360function log_pass
361{
362	_endlog $STF_PASS "$@"
363}
364
365# Perform cleanup and exit $STF_FAIL
366#
367# $@ - message text
368
369function log_fail
370{
371	_endlog $STF_FAIL "$@"
372}
373
374# Perform cleanup and exit $STF_UNRESOLVED
375#
376# $@ - message text
377
378function log_unresolved
379{
380	_endlog $STF_UNRESOLVED "$@"
381}
382
383# Perform cleanup and exit $STF_UNSUPPORTED
384#
385# $@ - message text
386
387function log_unsupported
388{
389	_endlog $STF_UNSUPPORTED "$@"
390}
391
392# Perform cleanup and exit $STF_UNTESTED
393#
394# $@ - message text
395
396function log_untested
397{
398	_endlog $STF_UNTESTED "$@"
399}
400
401function set_main_pid
402{
403	_MAINPID=$1
404}
405
406#
407# Internal functions
408#
409
410# Execute custom callback scripts on test failure
411#
412# callback script paths are stored in TESTFAIL_CALLBACKS, delimited by ':'.
413
414function _execute_testfail_callbacks
415{
416	typeset callback
417
418	while read -d ":" callback; do
419		if [[ -n "$callback" ]] ; then
420			log_note "Performing test-fail callback ($callback)"
421			$callback
422		fi
423	done <<<"$TESTFAIL_CALLBACKS:"
424}
425
426# Perform cleanup and exit
427#
428# $1 - stf exit code
429# $2-$n - message text
430
431function _endlog
432{
433	typeset logfile="/tmp/log.$$"
434	_recursive_output $logfile
435
436	typeset exitcode=$1
437	shift
438	(( ${#@} > 0 )) && _printline "$@"
439
440	#
441	# If we're running in a subshell then just exit and let
442	# the parent handle the failures
443	#
444	if [[ -n "$_MAINPID" && $$ != "$_MAINPID" ]]; then
445		log_note "subshell exited: "$_MAINPID
446		exit $exitcode
447	fi
448
449	if [[ $exitcode == $STF_FAIL ]] ; then
450		_execute_testfail_callbacks
451	fi
452
453	typeset stack=("${_CLEANUP[@]}")
454	log_onexit ""
455	typeset i=${#stack[@]}
456	while (( i-- )); do
457		typeset cleanup="${stack[i]}"
458		log_note "Performing local cleanup via log_onexit ($cleanup)"
459		$cleanup
460	done
461
462	exit $exitcode
463}
464
465# Output a formatted line
466#
467# $@ - message text
468
469function _printline
470{
471	if [[ -n "$ZTS_LOG_SUPPRESS_TIMESTAMP" ]] ; then
472		printf '[%(%FT%T.%6N)T] %s\n' now "$*"
473	else
474		echo "$@"
475	fi
476}
477
478# Output an error message
479#
480# $@ - message text
481
482function _printerror
483{
484	_printline ERROR: "$@"
485}
486
487# Output a success message
488#
489# $@ - message text
490
491function _printsuccess
492{
493	_printline SUCCESS: "$@"
494}
495
496# Output logfiles recursively
497#
498# $1 - start file
499# $2 - indicate whether output the start file itself, default as yes.
500
501function _recursive_output #logfile
502{
503	typeset logfile=$1
504
505	while [[ -e $logfile ]]; do
506		if [[ -z $2 || $logfile != $1 ]]; then
507			cat $logfile
508		fi
509		rm -f $logfile
510		logfile="$logfile.$$"
511	done
512}
513