lib.sh

#!/bin/bash

# get test-case information
SCRIPT_HOME="$(dirname "${BASH_SOURCE[0]}")"
# get test-case parent folder name
SCRIPT_HOME=$(cd "$SCRIPT_HOME/.." && pwd)
# shellcheck disable=SC2034 # external script can use it
SCRIPT_NAME="$0"  # get test-case script load name
# shellcheck disable=SC2034 # external script can use it
SCRIPT_PRAM="$*"  # get test-case parameter
# shellcheck disable=SC2034 # external script can use it
SOF_TEST_ALSA_STATE_FILENAME=/tmp/"${SCRIPT_NAME##*/}".$$.state

# Source from the relative path of current folder
# shellcheck source=case-lib/config.sh
source "$SCRIPT_HOME/case-lib/config.sh"
# shellcheck source=case-lib/opt.sh
source "$SCRIPT_HOME/case-lib/opt.sh"
# shellcheck source=case-lib/logging_ctl.sh
source "$SCRIPT_HOME/case-lib/logging_ctl.sh"
# shellcheck source=case-lib/pipeline.sh
source "$SCRIPT_HOME/case-lib/pipeline.sh"
# shellcheck source=case-lib/hijack.sh
source "$SCRIPT_HOME/case-lib/hijack.sh"

# source these last (and in this order) so they win
for f in /etc/sof/local_config.bash ${SCRIPT_HOME}/case-lib/local_config.bash; do
    if test -e "$f"; then
        dlogw "Sourcing local and optional $f"
        # shellcheck disable=SC1090
        source "$f"
    fi
done

# restrict bash version for some bash feature
[[ $(echo -e "$BASH_VERSION\n4.1"|sort -V|head -n 1) == '4.1' ]] || {
    dlogw "Bash version: ${BASH_VERSINFO[0]}.${BASH_VERSINFO[1]} should > 4.1"
    exit 2
}

# Add tools to command PATH
# this line equal `! $(echo $PATH|grep "$SCRIPT_HOME/tools")`
if [[ ! $PATH =~ $SCRIPT_HOME/tools ]]; then
    export PATH=$SCRIPT_HOME/tools:$PATH
fi

# setup SOFCARD id
if [ ! "$SOFCARD" ]; then
	# $1=$1 strips whitespaces
	SOFCARD=$(grep -v 'sof-probe' /proc/asound/cards |
		awk '/sof-[a-z]/ && $1 ~ /^[0-9]+$/ { $1=$1; print $1; exit 0;}')
fi


_SOF_TEST_LOCK_FILE=/tmp/sof-test-card"$SOFCARD".lock

# define min/max function
minvalue() { printf '%d' $(( "$1" < "$2"  ? "$1" : "$2" )); }

# This implements two important features:
#
# 1. Log the start of each test with the current ktime in journalctl.
#
# 2. Tries to detect concurrent sof-test instances. This is performed
#    using (hopefully) atomic filesystem operations and a shared
#    /tmp/sof-test-cardN.lock file that contains the process ID.  It's
#    some kind of a mutex except it's systematically "stolen" to avoid
#    deadlocks after a crash and increase the chances of more tests
#    failing when running concurrently. Past experience before this code
#    showed surprisingly high PASS rates when testing concurrently! (and
#    unvoluntarily).
#
#    `ln` and `mv` are used and hopefully atomic. It's almost sure they
#    are at the filesystem level but it can also depend on the coreutils
#    version according to the latest rumours. Even if they're not, the
#    race window is super small. Even if this code fails to detect
#    concurrency 1% of the time, detecting it 99% of the time is much
#    more than enough to spot reservation problems.
#
# 3. Register the func_exit_handler() EXIT trap that collects logs, kills
#    loggers and prints test results.
#
# 4. Waits for the FW to be successfully booted (can be disabled)
#
#
start_test()
{
    if is_subtest; then
        return 0
    fi

    test -z "${SOF_TEST_TOP_PID}" || {
        dlogw "SOF_TEST_TOP_PID=${SOF_TEST_TOP_PID} already defined, multiple lib.sh inclusions?"
        return 0
    }

    # func_exit_handler() is in hijack.sh
    trap 'func_exit_handler $?' EXIT

    if test -z "$MAX_WAIT_FW_LOADING"; then
        local _pltf; _pltf=$("$SCRIPT_HOME/tools/sof-dump-status.py" -p)
        case "$_pltf" in

            # broken i915 with long timeout, see comments in config.sh
            # add_slow_prototype_platform_here) MAX_WAIT_FW_LOADING=70;;

            # rt1011 i2c-10EC1011:00 needs 10 seconds on cml-hel-rt5682,
            # see https://github.com/thesofproject/sof-test/pull/1095
            cml) MAX_WAIT_FW_LOADING=13;;

            *)   MAX_WAIT_FW_LOADING=3;;
        esac
    fi

    # Check for whether SOF fW is loaded or not before starting any test.
    # Only start the polling for firmware boot complete when SOF soundcard is not available
    # setup_kernel_check_point has already -1 second to avoid TOCTOU race condition
    [ -n "$NO_POLL_FW_LOADING" ] || is_sof_used || {
        setup_kernel_check_point
        if poll_wait_for 1 "$MAX_WAIT_FW_LOADING" sof_firmware_boot_complete --since=@"$KERNEL_CHECKPOINT"; then
            dlogi "Good to start the test, FW is loaded!"
        else
            die "FW is not loaded for $MAX_WAIT_FW_LOADING"
        fi
    }

    export SOF_TEST_TOP_PID="$$"
    local prefix; prefix="ktime=$(ktime) sof-test PID=${SOF_TEST_TOP_PID}"
    local ftemp; ftemp=$(mktemp --tmpdir sof-test-XXXXX)
    printf '%s' "${SOF_TEST_TOP_PID}" > "$ftemp"

    # `ln` is supposedly atomic. `mv --no-clobber` is even more likely
    # to be atomic (depending on the coreutils version, see above) but
    # it fails with... an exit status 0!  Useless :-(
    ln "$ftemp" "${_SOF_TEST_LOCK_FILE}" || {
        local lock_pid; lock_pid=$(head -n 1 "${_SOF_TEST_LOCK_FILE}")

        if [ "${SOF_TEST_TOP_PID}" = "$lock_pid" ]; then
            # Internal error
            die "${_SOF_TEST_LOCK_FILE} with ${SOF_TEST_TOP_PID} already exists?!"
        fi

        # Assume this was left-over after a crash, keep running.
        # If another test is really running concurrently then stealing
        # the lock increases the chances of BOTH failing.
        local err_msg
        err_msg=$(printf '%s: %s already taken by PID %s! Stealing it...' \
                  "$prefix" "${_SOF_TEST_LOCK_FILE}" "$lock_pid")
        ln -f "$ftemp" "${_SOF_TEST_LOCK_FILE}"
        dloge "$err_msg"
        logger -p user.err "$err_msg"
    }
    rm "$ftemp"

    local start_msg="$prefix: starting"
    dlogi "$start_msg"
    logger -p user.info "$start_msg"

}

# See high-level description in start_test header above
#
stop_test()
{
    if is_subtest; then
        return 0
    fi

    local ftemp; ftemp=$(mktemp --tmpdir sof-test-XXXXX)
    local prefix; prefix="ktime=$(ktime) sof-test PID=${SOF_TEST_TOP_PID}"
    local err_msg

    # rename(3) is atomic. `mv` hopefully is too.
    mv "${_SOF_TEST_LOCK_FILE}" "$ftemp" || {
        err_msg="$prefix: lock file ${_SOF_TEST_LOCK_FILE} already removed! Concurrent testing?"
        dloge "$err_msg"
        logger -p user.err "$err_msg"
        return 1
    }
    printf '%s' "$SOF_TEST_TOP_PID" > "$ftemp".2

    diff -u "$ftemp".2 "$ftemp" || {
        err_msg="$prefix: unexpected value in ${_SOF_TEST_LOCK_FILE}! Concurrent testing?"
        dloge "$err_msg"
        logger -p user.err "$err_msg"
        return 1
    }

    local end_msg
    end_msg="$prefix: ending"

    dlogi "$end_msg"
    logger -p user.info "$end_msg"

    rm "$ftemp" "$ftemp".2
}


ktime()
{
    # Keep it coarse because of various delays.
    # TODO: does CLOCK_MONOTONIC match dmesg exactly?
    python3 -c \
       'import time; print("%d" % time.clock_gettime(time.CLOCK_MONOTONIC))'
}


# Arguments:
#
#   - poll interval in secs
#   - timeout in secs, rounded up to the next interval
#   - command and arguments
#
poll_wait_for()
{
    test $# -ge 3 ||
        die "poll_wait_for() invoked with $# arguments"

    local ival="$1"; shift
    local maxtime="$1"; shift

    printf "Polling '%s' every ${ival}s for ${maxtime}s\n" "$*"

    local waited=0 attempts=1 pass=true
    while ! "$@"; do
        if [ "$waited" -ge "$maxtime" ]; then
            pass=false
            break;
        fi
        sleep "$ival"
        : $((attempts++));  waited=$((waited+ival))
    done
    local timeinfo="${waited}s and ${attempts} attempts"
    if $pass; then
        printf "Completed '%s' after ${timeinfo}\n" "$*"
    else
        >&2 printf "Command '%s' timed out after ${timeinfo}\n" "$*"
    fi

    $pass
}


storage_checks()
{
    local megas max_sync
    local platf; platf=$(sof-dump-status.py -p)

    case "$platf" in
        # BYT Minnowboards run from SD cards.
        # BSW Cyan has pretty bad eMMC too.
        byt|cht|ehl) megas=4 ; max_sync=25 ;;
        *) megas=100; max_sync=7 ;;
    esac

    ( set -x
      # Thanks to CONT this does not actually timeout; it only returns a
      # non-zero exit status when taking too long.
      time timeout -s CONT "$max_sync" sudo sync || return $?
      # Spend a few seconds to test and show the current write speed
      timeout -s CONT 5 dd if=/dev/zero of=~/HD_TEST_DELETE_ME bs=1M count="$megas" conv=fsync ||
          return $?
      time timeout -s CONT "$max_sync" sudo sync
    ) || return $?

    rm ~/HD_TEST_DELETE_ME
}


setup_kernel_check_point()
{
    # Make the check point $SOF_TEST_INTERVAL second(s) earlier to avoid
    # log loss.  Note this may lead to an error caused by one test
    # appear in the next one, see comments in config.sh.  Add 3 extra
    # second to account for our own, sof-test delays after PASS/FAIL
    # decision: time spent collecting logs etc.
    if [ -z "$KERNEL_CHECKPOINT" ]; then
        KERNEL_CHECKPOINT=$(($(date +%s) - SOF_TEST_INTERVAL - 3))
    else
        # Not the first time we are called so this is a test
        # _iteration_. Add just one extra second in case a test makes
        # the mistake to call this function _after_ checking the logs.
        KERNEL_CHECKPOINT=$(($(date +%s) - 1))
    fi
}

# This function adds a fake error to dmesg (which is always saved by
# journald). It also adds it to kern.log, see why in comment below.
#
# It is surprisingly easy to write a test that always succeeds,
# especially in shell script and it has already happened a number of
# times. Temporarily add this function to a test under development to
# make sure it can actually report failures. Using this function is even
# more critical for testing changes to the test framework and especially
# error handling code.
#
# Sample usage: fake_kern_error "DRIVER ID: FAKE error $0 PID $$ $round"
#               fake_kern_error "asix 3-12.1:1.0 enx000ec668ad2a: Failed to write reg index 0x0000: -11"
fake_kern_error()
{
    local k_msg d boot_secs kern_log_prefix

    k_msg="$1"
    d=$(date '+%b %d %R:%S') # TODO: is this locale dependent?
    boot_secs=$(awk '{ print $1 }' < /proc/uptime)
    kern_log_prefix="$d $(hostname) kernel: [$boot_secs]"

    printf '<3>%s >/dev/kmsg\n' "$k_msg"  | sudo tee -a /dev/kmsg >/dev/null

    # From https://www.kernel.org/doc/Documentation/ABI/testing/dev-kmsg
    # It is not possible to inject to /dev/kmesg with the facility
    # number LOG_KERN (0), to make sure that the origin of the messages
    # can always be reliably determined.
    printf '%s %s >> kern.log\n' "$kern_log_prefix" \
           "$k_msg" | sudo tee -a /var/log/kern.log >/dev/null

}

# $1: optional (platform) string to strip. Useful for IPC4.
get_ldc_subdir()
{
    local strip_arg="$1"
    local subdir='intel/sof' # default

    local fw_path
    if fw_path=$(fw_reldir); then
            subdir=${fw_path%/} # strip any trailing slash
            subdir=${subdir%/community}
            subdir=${subdir%/intel-signed}
            subdir=${subdir%/dbgkey}
            test -z "$strip_arg" || subdir=${subdir%/"$strip_arg"}
    fi
    printf '%s' "$subdir"
}

# Prints the .ldc file found on stdout, logs on stderr.
find_ldc_file()
{
    local ldcFile
    # if user doesn't specify file path of sof-*.ldc, fall back to
    # /etc/sof/sof-PLATFORM.ldc, which is the default path used by CI.
    # and then on the standard location.
    if [ -n "$SOFLDC" ]; then
        ldcFile="$SOFLDC"
        >&2 dlogi "SOFLDC=${SOFLDC} overriding default locations"
    else
        local platf; platf=$(sof-dump-status.py -p) || {
            >&2 dloge "Failed to query platform with sof-dump-status.py"
            return 1
        }
        ldcFile=/etc/sof/sof-"$platf".ldc
        [ -e "$ldcFile" ] || {
            local subdir; subdir=$(get_ldc_subdir "$platf")
            ldcFile=/lib/firmware/"${subdir}"/sof-"$platf".ldc
        }
    fi

    [[ -e "$ldcFile" ]] || {
        >&2 dlogi "LDC file $ldcFile not found"
        return 1
    }
    printf '%s' "$ldcFile"
}

# Prints the syst collateal file found on stdout, logs on stderr.
find_syst_dict_file()
{
    local dict_file

    if [ -n "$SOFSYST" ]; then
        dict_file="$SOFSYST"
        >&2 dlogi "SOFSYST=${SOFSYST} overriding default locations"
    else
        # reuse LDC logic to set subdir
        local subdir; subdir=$(get_ldc_subdir)
        dict_file=/lib/firmware/"${subdir}"/mipi_syst_collateral.xml
    fi

    [[ -e "$dict_file" ]] || {
        >&2 dlogi "MIPI Sys-T Collateral file $dict_file not found"
        return 1
    }
    printf '%s' "$dict_file"
}

func_mtrace_collect()
{
    local clogfile="$1"

    if [ -z "$MTRACE" ]; then
        MTRACE=$(command -v mtrace-reader.py) || {
            dlogw 'No mtrace-reader.py found in PATH'
            return 1
        }
    fi

    local mtraceCmd=("$MTRACE")
    dlogi "Starting ${mtraceCmd[*]} >& $clogfile &"

    # Cleaned up by func_exit_handler() in hijack.sh
    #
    # We need "bash -c" because "sudo ... &" corrupts the terminal among
    # other issues, see bug #1151.
    # shellcheck disable=SC2024
    sudo bash -c "${mtraceCmd[*]} &" >& "$clogfile"
}

func_lib_log_post_process()
{
    # SyS-T log output a Zephyr feature, no need postprocess
    # if non-Zephyr firmware file under test
    is_firmware_file_zephyr || return 0

    local logfile="$LOG_ROOT"/mtrace.txt
    local outfile="$LOG_ROOT"/mtrace-decoded.csv

    # postprocess is not required if the test
    # configuration does not emit SysT-Cat log encoding
    grep -q "SYS-T RAW DATA:" "$logfile" || return 0

    # systprint tool is available via
    # - https://github.com/zephyrproject-rtos/mipi-sys-t
    # - https://github.com/MIPI-Alliance/public-mipi-sys-t
    if [ -z "$SYSTPRINT" ]; then
        SYSTPRINT=$(command -v systprint) || {
            dlogw "No systprint found in PATH, unable to post-process file $logfile"
            # TODO: make this fatal
            return 0
        }
    fi

    local dict_file
    dict_file=$(find_syst_dict_file) || {
        dlogw "SyS-T dict file not found, unable to post-process file $logfile"
        # TODO: make this fatal
        return 0
    }

    $SYSTPRINT -c "$dict_file" "$logfile" >"$outfile" || {
        dlogw "Error running systprint, unable to post-process file $logfile"
        # TODO: make this fatal
        return 0
    }
}

func_sof_logger_collect()
{
    logfile=$1
    logopt=$2
    ldcFile=$(find_ldc_file) || return $?

    if [ -z "$SOFLOGGER" ]; then
        SOFLOGGER=$(command -v sof-logger) || {
            dlogw 'No sof-logger found in PATH'
            return 1
        }
    fi

    test -x "$SOFLOGGER" || {
        dlogw "$SOFLOGGER not found or not executable"
        return 2
    }

    # The logger does not like empty '' arguments and $logopt can be
    # shellcheck disable=SC2206
    local loggerCmd=("$SOFLOGGER" $logopt -l "$ldcFile")
    dlogi "Starting ${loggerCmd[*]} > $logfile &"

    # Cleaned up by func_exit_handler() in hijack.sh
    #
    # We need "bash -c" because "sudo ... &" corrupts the terminal among
    # other issues, see bug #1151.
    # shellcheck disable=SC2024
    sudo bash -c "${loggerCmd[*]} &" > "$logfile"
}

SOF_LOG_COLLECT=0
# This function starts a logger in the background using '&'
#
# 0. Without any argument is it used to read the DMA trace
# continuously from /sys/kernel/debug/sof/trace.
#
# 1. It is also invoked at the end of a test with an argument other than
# '0' for a one-shot collection of the shared memory 'etrace' in the
# same directory. In that second usage, the caller is expected to sleep
# a little bit while the collection happens in the "pseudo-background".
#
# Note the sof-logger is not able to "stream" logs from the 'etrace'
# ring buffer (nor from any ring buffer), it can only take a snapshot of
# that ring buffer. For the DMA trace, the Linux kernel implements the
# streaming feature. See
# https://github.com/thesofproject/linux/issues/3275 for more info.
#
# Zephyr's cavstool.py implements streaming and is able to read
# continously from the etrace ring buffer.
func_lib_start_log_collect()
{
    local is_etrace=${1:-0} ldcFile
    local log_file log_opt

    if func_hijack_setup_sudo_level ;then
        # shellcheck disable=SC2034 # external script will use it
        SOF_LOG_COLLECT=1
    else
        >&2 dlogw "without sudo permission to run logging command"
        return 3
    fi

    if [ "X$is_etrace" == "X0" ]; then
        if is_ipc4 && is_firmware_file_zephyr; then
            logfile="$LOG_ROOT"/mtrace.txt
            func_mtrace_collect "$logfile"
        else
            log_file=$LOG_ROOT/slogger.txt
            log_opt="-t"
            func_sof_logger_collect "$log_file" "$log_opt"
        fi
    else # once-off etrace collection at end of test
        if is_ipc4; then
            dlogi "No end of test etrace collection for IPC4"
        else
            log_file=$LOG_ROOT/etrace.txt
            log_opt=""
            func_sof_logger_collect "$log_file" "$log_opt"
        fi
    fi

}

check_error_in_fw_logfile()
{
    local platf; platf=$(sof-dump-status.py -p)

    case "$platf" in
        byt|bdw|bsw)
            # Maybe downgrading this to WARN would be enough, see #799
            #  src/trace/dma-trace.c:654  ERROR dtrace_add_event(): number of dropped logs = 8
            dlogw 'not looking for ERROR on BYT/BDW because of known DMA issues #4333 and others'
            return 0
            ;;
    esac

    test -r "$1" || {
        dloge "file NOT FOUND: '$1'"
        return 1
    }
    # -B 2 shows the header line when the first etrace message is an ERROR
    # -A 1 shows whether the ERROR is last or not.
    if (set -x
        grep -B 2 -A 1 -i --word-regexp -e 'ERR' -e 'ERROR' -e '<err>' -e OSError "$1"
       ); then
        # See internal Intel bug #448
        dlogw 'An HTML display bug hides the bracketed Zephyr &lt;loglevels&gt; in this tab,'
        dlogw 'switch to the tab with the complete logs to see the log levels.'
        return 1
    fi
}

# Calling this function is often a mistake because the error message
# from the actual sudo() function in hijack.sh is better: it is
# guaranteed to print the command that needs sudo and give more
# information. func_lib_check_sudo() is useful only when sudo is
# optional and when its warning can be ignored (with '|| true') but in
# the past it has been used to abort the test immediately and lose the
# better error message from sudo().
func_lib_check_sudo()
{
    local cmd="${1:-Unknown command}"
    func_hijack_setup_sudo_level || {
        dlogw "$cmd needs root privilege to run, please use NOPASSWD or cached credentials"
        return 2
    }
}

systemctl_show_pulseaudio()
{
    printf '\n'
    local domain
    for domain in --system --global --user; do
        ( set -x
          systemctl "$domain" list-unit-files --all '*pulse*'
        ) || true
        printf '\n'
    done

    printf 'For %s ONLY:\n' "$(id -un)"
    ( set -x
      systemctl --user list-units --all '*pulse*'
    ) || true
    printf '\n'

    # pgrep ouput is nicer because it hides itself, however pgrep does
    # not show a critical information: the userID which can be not us
    # but 'gdm'!
    # shellcheck disable=SC2009
    ps axu | grep -i pulse
    >&2 printf 'ERROR: %s fails semi-randomly when pulseaudio is running\n' \
        "$(basename "$0")"

    >&2 printf '\nTry: sudo systemctl --global mask pulseaudio.{socket,service} and reboot.
    --global is required for session managers like "gdm"
'
    # We cannot suggest "systemctl --user mask" for a 'gdm' user
    # because we can't 'su' to it and access its DBUS, so we suggest
    # --global to keep it simple. If --global is too strong for you, you
    # can manually create a
    # /var/lib/gdm3/.config/systemd/user/pulseaudio.service -> /dev/null
    # symlink
}

declare -a PULSECMD_LST
declare -a PULSE_PATHS

func_lib_disable_pulseaudio()
{
    [[ "${#PULSECMD_LST[@]}" -ne 0 ]] && return
    # store current pulseaudio command
    readarray -t PULSECMD_LST < <(ps -C pulseaudio -o user,cmd --no-header)
    [[ "${#PULSECMD_LST[@]}" -eq 0 ]] && return
    func_lib_check_sudo 'disabling pulseaudio'
    # get all running pulseaudio paths
    readarray -t PULSE_PATHS < <(ps -C pulseaudio -o cmd --no-header | awk '{print $1}'|sort -u)
    for PA_PATH in "${PULSE_PATHS[@]}"
    do
        # rename pulseaudio before kill it
        if [ -x "$PA_PATH" ]; then
            sudo mv -f "$PA_PATH" "$PA_PATH.bak"
        fi
    done
    sudo pkill -9 pulseaudio
    sleep 1s # wait pulseaudio to be disabled
    if [ ! "$(ps -C pulseaudio --no-header)" ]; then
        dlogi "Pulseaudio disabled"
    else
        # if failed to disable pulseaudio before running test case, fail the test case directly.
        die "Failed to disable pulseaudio"
    fi
}

func_lib_restore_pulseaudio()
{
    [[ "${#PULSECMD_LST[@]}" -eq 0 ]] && return
    func_lib_check_sudo 're-enabling pulseaudio'
    # restore pulseaudio
    for PA_PATH in "${PULSE_PATHS[@]}"
    do
        if [ -x "$PA_PATH.bak" ]; then
            sudo mv -f "$PA_PATH.bak" "$PA_PATH"
        fi
    done
    # start pulseaudio
    local line
    for line in "${PULSECMD_LST[@]}"
    do
        # Both the user and the command are the same $line var :-(
        # shellcheck disable=SC2086
        nohup sudo -u $line >/dev/null &
    done
    # now wait for the pulseaudio restore in the ps process
    timeout=10
    dlogi "Restoring pulseaudio"
    for wait_time in $(seq 1 $timeout)
    do
        sleep 1s
        [ -n "$(ps -C pulseaudio --no-header)" ] && break
        if [ "$wait_time" -eq $timeout ]; then
             dlogi "Time out. Pulseaudio not restored in $timeout seconds"
             return 1
        fi
    done
    dlogi "Restoring pulseaudio takes $wait_time seconds"
    unset PULSECMD_LST
    unset PULSE_PATHS
    declare -ag PULSECMD_LST
    declare -ag PULSE_PATHS
    return 0
}

func_lib_get_random()
{
    # RANDOM: Each time this parameter is referenced, a random integer between 0 and 32767 is generated
    local random_max=$1 random_min=$2 random_scope
    random_scope=$(( random_max - random_min ))
    if [ $# -ge 2 ];then
        echo $(( RANDOM % random_scope + random_min ))
    elif [ $# -eq 1 ];then
        echo $(( RANDOM % random_max ))
    else
        echo $RANDOM
    fi
}

func_lib_lsof_error_dump()
{
    local file="$1" ret
    # lsof exits the same '1' whether the file is missing or not open :-(
    [[ ! -c "$file" ]] && return
    ret=$(lsof "$file") || true
    if [ "$ret" ];then
        dloge "Sound device $file is in use:"
        echo "$ret"
    fi
}

func_lib_get_tplg_path()
{
    local tplg=$1
    if [[ -z "$tplg" ]]; then   # tplg given is empty
        return 1
    elif [[ -f "$tplg" ]]; then
        realpath "$tplg"
    elif [[ -f "$TPLG_ROOT/$tplg" ]]; then
        echo "$TPLG_ROOT/$tplg"
    else
        return 1
    fi

    return 0
}

func_lib_check_pa()
{
    pactl stat || {
        dloge "pactl stat failed"
        return 1
    }
}

# We must not quote SOF_ALSA_OPTS and disable SC2086 below for two reasons:
#
# 1. We want to support multiple parameters in a single variable, in
#    other words we want to support this:
#
#      SOF_ALSA_OPTS="--foo --bar"
#      aplay $SOF_ALSA_OPTS ...
#
# 2. aplay does not ignore empty arguments anyway, in other words this
#    does not work anyway:
#
#      SOF_ALSA_OPTS=""
#      aplay "$SOF_ALSA_OPTS" ...
#
# This is technically incorrect because it means our SOF_ALSA_OPTS
# cannot support whitespace, for instance this would be split in two
# options: --bar="aaaa and bbbb"
#
#      SOF_ALSA_OPTS='--foo --bar="aaaa bbbb"'
#
# To do this "correctly" SOF_ALSA_OPTS etc. should be arrays.
# From https://mywiki.wooledge.org/BashGuide/Arrays "The only safe way
# to represent multiple string elements in Bash is through the use of
# arrays."
#
# However, 1. arrays would complicate the user interface 2. ALSA does not
# seem to need arguments with whitespace or globbing characters.

# SOF_ALSA_TOOL:
# This option is used for selecting tool for testing,
# So far, supported tools are 'alsa' and 'tinyalsa'
# To select appropriate tool, set SOF_ALSA_TOOL to one of above
# before using 'aplay_opts' or 'arecord_opts' function.
# Default is SOF_ALSA_TOOL='alsa'

: "${SOF_ALSA_TOOL:="alsa"}"

# Function to extract the card number and device number from $dev option (e.g., hw:0,10)
parse_audio_device() {
    # Extract the card number (e.g., "0" from hw:0,10)
    card_nr=$(printf '%s' "$1" | cut -d ':' -f2 | cut -d ',' -f1)

    # Extract the device number (e.g., "10" from hw:0,10)
    dev_nr=$(printf '%s' "$1" | cut -d ',' -f2)
}

# Function to extract the numeric format value from the PCM sample formats
# There is passes PCM sample format while using ALSA tool (arecord)
# While using TinyALSA (tinycap -b) we need to convert PCM sample fomrat to bits.
extract_format_number() {
    # (e.g., extracting '16' from 'S16_LE')
    printf '%s' "$1" | grep '[0-9]\+' -o
}

# Initialize the parameters using for audio testing.
# shellcheck disable=SC2034
initialize_audio_params()
{
    local idx="$1"

    channel=$(func_pipeline_parse_value "$idx" channel)
    rate=$(func_pipeline_parse_value "$idx" rate)
    fmts=$(func_pipeline_parse_value "$idx" fmt)
    dev=$(func_pipeline_parse_value "$idx" dev)
    pcm=$(func_pipeline_parse_value "$idx" pcm)
    type=$(func_pipeline_parse_value "$idx" type)
    snd=$(func_pipeline_parse_value "$idx" snd)

    if [[ "$SOF_ALSA_TOOL" = "tinyalsa" ]]; then
       parse_audio_device "$dev"
    fi
}

aplay_opts()
{
    if [[ "$SOF_ALSA_TOOL" = "tinyalsa" ]]; then
        # shellcheck disable=SC2154
        if ! sox -n -r "$rate" -c "$channel" noise.wav synth "$duration" white; then
            printf 'Error: sox command failed.\n' >&2
	    return 1
	fi
        dlogc "tinyplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS -D $card_nr -d $dev_nr  -i wav noise.wav"
	# shellcheck disable=SC2086
        tinyplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS -D "$card_nr" -d "$dev_nr"  -i wav noise.wav
    elif [[ "$SOF_ALSA_TOOL" = "alsa" ]]; then
        dlogc "aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS $*"
        # shellcheck disable=SC2086
        aplay $SOF_ALSA_OPTS $SOF_APLAY_OPTS "$@"
    else
        die "Unknown ALSA tool: $SOF_ALSA_TOOL"
    fi
}

arecord_opts()
{

    if [[ "$SOF_ALSA_TOOL" = "tinyalsa" ]]; then
        # shellcheck disable=SC2154
        # Global variable "$fmt_elem" from check_capture.sh test script
	format=$(extract_format_number "$fmt_elem")
	dlogc "tinycap $SOF_ALSA_OPTS $SOF_ARECORD_OPTS $file -D $card_nr -d $dev_nr -c $channel -t $duration -r $rate -b $format"
	# shellcheck disable=SC2086
        tinycap $SOF_ALSA_OPTS $SOF_ARECORD_OPTS "$file" -D "$card_nr" -d "$dev_nr" -c "$channel" -t "$duration" -r "$rate" -b "$format"
    elif [[ "$SOF_ALSA_TOOL" = "alsa" ]]; then
        dlogc "arecord $SOF_ALSA_OPTS $SOF_ARECORD_OPTS $*"
        # shellcheck disable=SC2086
        arecord $SOF_ALSA_OPTS $SOF_ARECORD_OPTS "$@"
    else
        die "Unknown ALSA tool: $SOF_ALSA_TOOL"
    fi
}

die()
{
    dloge "$@"
    exit 1
}

skip_test()
{
    dlogw 'SKIP test because:'
    dlogw "$@"
    # See func_exit_handler()
    exit 2
}

is_sof_used()
{
    grep -q "sof" /proc/asound/cards;
}

# a wrapper to journalctl with required style
journalctl_cmd()
{
   sudo journalctl -k -q --no-pager --utc --output=short-monotonic \
     --no-hostname "$@"
}

# Force the exit handler to collect all the logs since boot time instead
# of just the last test iteration.
disable_kernel_check_point()
{
    KERNEL_CHECKPOINT="disabled"
}

# "$@" is optional, usually: --since=@"$epoch_checkpoint"
# shellcheck disable=SC2120
sof_firmware_boot_complete()
{
    journalctl_cmd "$@" | grep -i 'sof.*firmware[[:blank:]]*boot[[:blank:]]*complete'
}

# If the firmware is loaded then you probably want to use the newer
# 'is_firmware_file_zephyr()' instead. Zephyr will have no .ldc file in
# the future.
is_zephyr_ldc()
{
    local ldcFile
    ldcFile=$(find_ldc_file) || {
        dloge '.ldc file not found, assuming XTOS firmware'
        return 1
    }
    local znum
    znum=$(strings "$ldcFile" | grep -c -i zephyr)
    # As of Nov. 2021, znum ~= 30 for Zephyr and 0 for XTOS
    test "$znum" -gt 10
}

# Prints the relative firmware subdirectory: e.g. `intel/sof-ipc4/tgl/community`
fw_reldir()
{
    local profile_path='/sys/kernel/debug/sof/fw_profile/fw_path'
    if sudo test -e $profile_path; then
        sudo cat $profile_path
        return 0
    fi

    # 1st fallback
    local param_path mod_param='/sys/module/snd_sof_pci/parameters/fw_path'
    if test -e $mod_param; then
        param_path=$(cat $mod_param)
        if [ "$param_path" != '(null)' ]; then
            printf '%s' "$param_path"
            return 0
        fi
    fi

    # 2nd fallback: old kernel or firmware not loaded
    local from_klogs
    from_klogs=$(fw_relfilepath_from_klogs) || {
        >&2 dloge 'fw_reldir: 2nd, klog fallback failed.'
        return 1
    }
    printf '%s' "$(dirname "$from_klogs")"
}

# Prints the relative firmware filepath: e.g. `intel/sof-ipc4/tgl/community/sof-tgl.ri`
#
# Some of the code duplicates fw_reldir() above. Unfortunately can't re-use and invoke
# fw_reldir() here because of small, logical differences. For instance, a defined
# `parameters/fw_path` is enough for fw_reldir() function to succeed but fw_relfilepath()
# needs BOTH `parameters/fw_path` and `parameters/fw_filename` at the same time.
fw_relfilepath()
{
    local fw_profile='/sys/kernel/debug/sof/fw_profile'
    if sudo test -e "$fw_profile"/fw_path; then
        printf '%s/%s' "$(sudo cat "$fw_profile"/fw_path)" \
               "$(sudo cat "$fw_profile"/fw_name)"

        return 0
    fi

    # 1st fallback
    local fw_params='/sys/module/snd_sof_pci/parameters'
    if test -e "$fw_params"/fw_path; then
        local _dir _filename
        _dir=$(cat "$fw_params"/fw_path)
        _filename=$(cat "$fw_params"/fw_filename)
        # Corner case: we could got out on a limb and try to find the filename somewhere
        # else when we have only the directory?  Or maybe not.
        if [ "$_dir" != '(null)' ] && [ "$_filename" != '(null)' ]; then
            printf '%s/%s' "$_dir" "$_filename"
            return 0
        fi
    fi

    # 2nd fallback: old kernel or firmware not loaded. SLOW.
    local from_klogs
    from_klogs=$(fw_relfilepath_from_klogs) || {
        >&2 dloge 'fw_relfilepath: 2nd, klog fallback failed.'
        return 1
    }
    printf '%s' "$from_klogs"
}

fw_relfilepath_from_klogs()
{
    local rel_filepath
    rel_filepath=$(journalctl -k |
        awk '/sof.*[[:blank:]]request_firmware[[:blank:]]/ {
               sub(/^.*request_firmware/,""); last_loaded_file=$1
             }
         END { print last_loaded_file }'
            )

    [ -n "$rel_filepath" ] || {
        >&2 dloge 'Firmware filepath not found in kernel logs. No firmware loaded or debug option disabled?'
        return 1
    }

    printf '%s' "$rel_filepath"
}

is_firmware_file_zephyr()
{
    local firmware_path znum

    { firmware_path=$(fw_relfilepath) && test -r /lib/firmware/"$firmware_path"; } ||
        die "Firmware path ${firmware_path} not found."

    znum=$(strings "/lib/firmware/$firmware_path" | grep -c -i zephyr)
    test "$znum" -gt 10
}

is_ipc4()
{
    local ipc_type

    if ipc_type=$(sudo cat /sys/kernel/debug/sof/fw_profile/ipc_type); then
	# "cat" was successful
	case $ipc_type in
	    0) return 1;; # IPC3 found
	    1) return 0;; # IPC4 found. in shell, success = error code 0 = "true"
	    *) die "invalid ipc_type in /sys/kernel/debug/sof/ipc_type=$ipc_type";;
	esac
    fi

    dlogw "using pre kernel 6.9 backwards-compatible fallback with ipc_type kernel parameter"
    if ipc_type=$(cat /sys/module/snd_sof_pci/parameters/ipc_type); then
	# "cat" was successful
	case $ipc_type in
	    -1)
		dlogw "the ipc_type parameter is not set, assume IPC3 was used"
		return 1;;
	    0)	# the parameter is set, IPC3 was used.
		return 1;;
	    1) 	# the parameter is set, IPC4 was used.
		return 0;; # in shell, success = error code 0 = "true"
	    *)	die "invalid ipc_type in /sys/module/snd_sof_pci/parameters/ipc_type=$ipc_type";;
	esac
    fi

    dlogw "/sys/module/snd_sof_pci/parameters/ipc_type does not exist, assuming IPC3 was used"
    return 1
}

logger_disabled()
{
    # Disable logging when available...
    if [ "${OPT_VAL['s']}" -eq 0 ]; then
        return 0
    fi

    # ... across all tests at once.
    # In the future we should support SOF_LOGGING=etrace (only), see
    # sof-test#726
    if [ "$SOF_LOGGING" == 'none' ]; then
        dlogi 'SOF logs collection globally disabled by SOF_LOGGING=none'
        return 0
    fi

    if is_ipc4 && ! is_firmware_file_zephyr; then
        dlogi 'IPC4 FW logging only support with SOF Zephyr build'
        dlogi 'SOF logs collection is globally disabled.'
        return 0
    fi

    return 1
}

print_module_params()
{
    echo "--------- Printing module parameters ----------"
    grep -H ^ /sys/module/snd_intel_dspcfg/parameters/* || true

    # for all the *sof* modules
    grep -H ^ /sys/module/*sof*/parameters/* || true

    # all snd_hda* modules
    grep -H ^ /sys/module/snd_hda*/parameters/* || true
    echo "----------------------------------------"

    echo "--------- Printing debugfs settings ----------"
    # Need /bin/sh to expand '*' as root.
    # Need "|| true" to support older kernels.
    sudo /bin/sh -c 'grep -H ^ /sys/kernel/debug/sof/fw_profile/*' || true
    echo "----------------------------------------------"
}

# "$@" is optional, typically: --since=@"$epoch".
# shellcheck disable=SC2120
grep_firmware_info_in_logs()
{
    # dump the version info and ABI info
    # "head -n" makes this compatible with set -e.
    journalctl_cmd "$@" | grep "Firmware info" -A1 | head -n 12
    # For dumping the firmware information when DUT runs IPC4 mode
    journalctl_cmd "$@" | grep "firmware version" -A1 | head -n 12
    # dump the debug info
    journalctl_cmd "$@" | grep "Firmware debug build" -A3 | head -n 12
}

# check if NTP Synchronized, if so return 0 otherwise return 1
check_ntp_sync()
{
    # Check this device time is NTP Synchronized.
    timedatectl show | grep -q "NTPSynchronized=yes"
}

# alsabat will return -2 for "C.UTF-8" locale
# every case with alsabat should call this at beginning
check_locale_for_alsabat()
{
    if locale | grep -i 'C.utf-8'; then
        die 'Try C.utf8 instead, see https://github.com/alsa-project/alsa-utils/issues/192'
    fi
}

re_enable_ntp_sync()
{
    # disable synchronization first
    sudo timedatectl set-ntp false

    # enable ntp sync. This will trigger initial synchronization to time server
    sudo timedatectl set-ntp true
}

# check-alsabat.sh need to run optimum alsa control settings
# param1: platform name
set_alsa_settings()
{
    # ZEPHYR platform shares same tplg, remove '_ZEPHYR' from platform name
    local PNAME="${1%_ZEPHYR}"
    dlogi "Run alsa setting for $PNAME"
    case $PNAME in
        APL_UP2_NOCODEC | CML_RVP_NOCODEC | JSL_RVP_NOCODEC | TGLU_RVP_NOCODEC | ADLP_RVP_NOCODEC | TGLH_RVP_NOCODEC | ADLP_RVP_NOCODEC-ipc3 | CML_RVP_NOCODEC-ipc3 | JSL_RVP_NOCODEC-ipc3)
            # common nocodec alsa settings
            "$SCRIPT_HOME"/alsa_settings/CAVS_NOCODEC.sh
        ;;
        TGLU_RVP_NOCODEC_CI | ADLP_RVP_NOCODEC_CI)
            # common nocodec_ci alsa settings
            "$SCRIPT_HOME"/alsa_settings/CAVS_NOCODEC_CI.sh
        ;;
        TGLU_RVP_NOCODEC_IPC4ZPH | ADLP_RVP_NOCODEC_IPC4ZPH | ADLP_RVP_NOCODEC-ipc4 | TGLU_RVP_NOCODEC-ipc4 | MTLP_RVP_NOCODEC | MTLP_RVP_NOCODEC-multicore-2cores | MTLP_RVP_NOCODEC-multicore-3cores | LNLM_RVP_NOCODEC)
            dlogi "Use reset_sof_volume function to set amixer setting."
	;;
        *)
            # if script name is same as platform name, default case will handle all
            if [ -f "$SCRIPT_HOME"/alsa_settings/"$PNAME".sh ]; then
                "$SCRIPT_HOME"/alsa_settings/"$PNAME".sh
            else
                dlogw "alsa setting for $PNAME is not available"
            fi
        ;;
    esac
}

reset_sof_volume()
{
    # set all PGA* volume to 0dB
    if [[ "$SOF_ALSA_TOOL" = "alsa" ]]; then
        amixer -Dhw:0 scontrols | sed -e "s/^.*'\(.*\)'.*/\1/" |grep -E 'PGA|gain' |

        while read -r mixer_name
        do
            if is_ipc4; then
                amixer -Dhw:0 -- sset "$mixer_name" 100%
            else
               amixer -Dhw:0 -- sset "$mixer_name" 0dB
            fi
        done
    elif [[ "$SOF_ALSA_TOOL" = "tinyalsa" ]]; then
        tinymix -D0 controls | sed -e "s/^.*'\(.*\)'.*/\1/" |grep -E 'PGA|gain' |

        while read -r mixer_name
        do
            if is_ipc4; then
                tinymix -D0 set "$mixer_name" 100%
            else
                tinymix -D0 set "$mixer_name" 0dB
            fi
        done
    else
         echo "Unknown alsa tool $SOF_ALSA_TOOL"
    fi
}

DO_PERF_ANALYSIS=0

perf_analyze()
{
    local perf_cmd

    [ "X$DO_PERF_ANALYSIS" == "X1" ] || return 0

    dlogi "Checking SOF component performance"
    if [ -e "$LOG_ROOT/mtrace.txt" ]; then
        if [ -e "$LOG_ROOT/dmesg.txt" ]; then
            perf_cmd="sof_perf_analyzer.py --kmsg=$LOG_ROOT/dmesg.txt --out2html $LOG_ROOT/sof_perf.html $LOG_ROOT/mtrace.txt"
        else
            perf_cmd="sof_perf_analyzer.py --out2html $LOG_ROOT/sof_perf.html $LOG_ROOT/mtrace.txt"
        fi
        dlogc "$perf_cmd"
        eval "$perf_cmd" || {
            dloge "SOF component performace analysis tool exit with error"
            return 1
        }
    else
        dloge "Firmware trace file not found"
        return 1
    fi
}

# Restore the machine state from a file.
# Should be triggered at the end of
# every test touching ALSA.
# Couple with save_machine_state.
restore_alsa_state()
{
    dlogi "restore_alsa_state called in ${SOF_TEST_ALSA_STATE_FILENAME}"
    if [ -f "${SOF_TEST_ALSA_STATE_FILENAME}" ]; then
        dlogi "restore_alsa_state found a relevant state file."
        alsactl restore --file "${SOF_TEST_ALSA_STATE_FILENAME}" --pedantic --no-ucm --no-init-fallback || dlogi "alsactl state restoration failed!"
        rm "${SOF_TEST_ALSA_STATE_FILENAME}" || dlogi "Old state file removal failed!"
    fi
}

# Save the machine state to a file.
# Should be used at the start of
# every test touching ALSA.
# Coupled with restore_machine_state
# on an exit signal inside func_exit_handler.
save_alsa_state()
{
    dlogi "save_alsa_state called in ${SOF_TEST_ALSA_STATE_FILENAME}"
    alsactl store --file "${SOF_TEST_ALSA_STATE_FILENAME}" || dlogi "alsactl state storage failed!"
}