From f08338ddbacf3e7f7b61b3eec7596364d6e71203 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Mon, 26 Sep 2022 15:33:48 +0800 Subject: [PATCH 1/7] lib.sh: move logger collection to a function Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 68 +++++++++++++++++++++++++++---------------------- 1 file changed, 38 insertions(+), 30 deletions(-) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 33f54d0d..6a9c63db 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -293,6 +293,33 @@ find_ldc_file() printf '%s' "$ldcFile" } +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[*]}" + # Cleaned up by func_exit_handler() in hijack.sh + # shellcheck disable=SC2024 + sudo "${loggerCmd[@]}" > "$logfile" & +} + SOF_LOG_COLLECT=0 # This function starts a logger in the background using '&' # @@ -315,29 +342,7 @@ SOF_LOG_COLLECT=0 func_lib_start_log_collect() { local is_etrace=${1:-0} ldcFile - - ldcFile=$(find_ldc_file) || return $? - - local logopt="-t" - - 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 - } - - if [ "X$is_etrace" == "X0" ];then - logfile=$LOG_ROOT/slogger.txt - else - logfile=$LOG_ROOT/etrace.txt - logopt="" - fi + local log_file log_opt if func_hijack_setup_sudo_level ;then # shellcheck disable=SC2034 # external script will use it @@ -347,13 +352,16 @@ func_lib_start_log_collect() return 3 fi - # The logger does not like empty '' arguments and $logopt can be - # shellcheck disable=SC2206 - local loggerCmd=("$SOFLOGGER" $logopt -l "$ldcFile") - dlogi "Starting ${loggerCmd[*]}" - # Cleaned up by func_exit_handler() in hijack.sh - # shellcheck disable=SC2024 - sudo "${loggerCmd[@]}" > "$logfile" & + if [ "X$is_etrace" == "X0" ]; then + log_file=$LOG_ROOT/slogger.txt + log_opt="-t" + func_sof_logger_collect "$log_file" "$log_opt" + else + log_file=$LOG_ROOT/etrace.txt + log_opt="" + func_sof_logger_collect "$log_file" "$log_opt" + fi + } check_error_in_file() From 7687f200cc10f2f11d64fb78df6c89639ee3bbb4 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Wed, 14 Sep 2022 09:33:51 +0800 Subject: [PATCH 2/7] lib.sh: add a function for mtrace collection mtrace is a new logging tool. Tool to stream data from Linux SOF driver mtrace debugfs interface to standard output. Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 6a9c63db..4a412f01 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -293,6 +293,24 @@ find_ldc_file() printf '%s' "$ldcFile" } +func_mtrace_collect() +{ + local clogfile=$LOG_ROOT/mtrace.txt + + 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[*]}" + # Cleaned up by func_exit_handler() in hijack.sh + # shellcheck disable=SC2024 + sudo "${mtraceCmd[@]}" >& "$clogfile" & +} + func_sof_logger_collect() { logfile=$1 From 8bc5310ef8c2ed32951ea3b7a2a91bfab79d15e2 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Tue, 27 Sep 2022 17:37:29 +0800 Subject: [PATCH 3/7] lib.sh: rename the ipc4_used to is_ipc4 Align the name with other similar functions and refine the is_ipc4 function. Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 16 ++++++++-------- 1 file changed, 8 insertions(+), 8 deletions(-) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 4a412f01..8ba04ae6 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -672,7 +672,7 @@ is_zephyr() test "$znum" -gt 10 } -ipc4_used() +is_ipc4() { local ipc_type ipc_file=/sys/module/snd_sof_pci/parameters/ipc_type @@ -685,12 +685,12 @@ ipc4_used() # If /sys/module/snd_sof_pci/parameters/ipc_type exists # If the value of file ipc_type is: - # 0: DUT runs IPC3 mode, ipc_used return 1(false) - # 1: DUT runs IPC4 mode, ipc4_used return 0(true) - [ "$ipc_type" -eq 1 ] || { - return 1 - } - return 0 + # -1: DUT runs IPC3 mode, is_ipc4 return 1(false) + # 1: DUT runs IPC4 mode, is_ipc4 return 0(true) + if [ "$ipc_type" -eq 1 ]; then + return 0 + fi + return 1 } logger_disabled() @@ -715,7 +715,7 @@ logger_disabled() return 0 fi - ipc4_used && { + is_ipc4 && { # TODO: # Need to remove disabling sof-logger # after sof-logger support for IPC4 has been provided in the future From 56cbcdcd75e341e23ad38eab327b2ef33c1a0a7f Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Mon, 26 Sep 2022 16:46:18 +0800 Subject: [PATCH 4/7] lib.sh: add a function to check if the firmware file is built with zephyr This function can check if the running firmware file is built with Zephyr. Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 8ba04ae6..0efa9f72 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -672,6 +672,31 @@ is_zephyr() test "$znum" -gt 10 } +is_firmware_file_zephyr() +{ + local firmware_name firmware_path znum platform + # get the FW name and path + # TODO: optimize this part after driver can expose the FW path to userspace via debugfs + if is_ipc4; then + firmware_name=dsp_basefw.bin + fw_mod_para=/sys/module/snd_sof_pci/parameters/fw_path + if [ -s "$fw_mod_para" ]; then + firmware_path=$(cat $fw_mod_para) + else + # TODO: let the kernel driver expose the FW path + # and get the FW path by grepping journalctl. + return 1 + fi + else # for IPC3 + platform=$(sof-dump-status.py -p) + firmware_name=sof-$platform.ri + firmware_path=$(sof-dump-status.py -P) + fi + + znum=$(strings "/lib/firmware/$firmware_path/$firmware_name" | grep -c -i zephyr) + test "$znum" -gt 10 +} + is_ipc4() { local ipc_type From 3cd7634fe26540ab08d71f08dfebec401cff87f3 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Wed, 28 Sep 2022 09:21:29 +0800 Subject: [PATCH 5/7] lib.sh: add a function to check if the firmware file is built with zephyr This function can check if the running firmware file is built with Zephyr. Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 0efa9f72..fd275d37 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -683,9 +683,9 @@ is_firmware_file_zephyr() if [ -s "$fw_mod_para" ]; then firmware_path=$(cat $fw_mod_para) else - # TODO: let the kernel driver expose the FW path - # and get the FW path by grepping journalctl. - return 1 + # # FIXME: the kernel driver should give us the FW path + # https://github.com/thesofproject/linux/issues/3867 + die "Failed to get the IPC4 FW path." fi else # for IPC3 platform=$(sof-dump-status.py -p) From e596b5d5e7a878391b87b75f2cb06a25d5756245 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Tue, 27 Sep 2022 17:43:43 +0800 Subject: [PATCH 6/7] lib.sh: enable the mtrace for IPC4 Zephyr platforms The mtrace is only support IPC4 platforms and mtrace should run while tests are running ATM. If mtrace is not running, DSP will stop outputting logs when buffer is full. So we need to keep the mtrace running during the test, or you won't see the error log. Signed-off-by: Keqiao Zhang --- case-lib/lib.sh | 36 ++++++++++++++++++++---------------- 1 file changed, 20 insertions(+), 16 deletions(-) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index fd275d37..a9c6fd0f 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -366,18 +366,26 @@ func_lib_start_log_collect() # shellcheck disable=SC2034 # external script will use it SOF_LOG_COLLECT=1 else - >&2 dlogw "without sudo permission to run $SOFLOGGER command" + >&2 dlogw "without sudo permission to run logging command" return 3 fi if [ "X$is_etrace" == "X0" ]; then - log_file=$LOG_ROOT/slogger.txt - log_opt="-t" - func_sof_logger_collect "$log_file" "$log_opt" - else - log_file=$LOG_ROOT/etrace.txt - log_opt="" - func_sof_logger_collect "$log_file" "$log_opt" + if is_ipc4 && is_firmware_file_zephyr; then + func_mtrace_collect + 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 } @@ -740,15 +748,11 @@ logger_disabled() return 0 fi - is_ipc4 && { - # TODO: - # Need to remove disabling sof-logger - # after sof-logger support for IPC4 has been provided in the future - dlogi 'Currenly sof-logger is not supported when running IPC4 mode' - dlogi 'SOF logs collection is globally disabled because DUT is running IPC4 mode' + 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 - } - dlogi 'DUT is running IPC3 mode' + fi return 1 } From 9c926a46c1f42ac106437bbb496d64900680fb59 Mon Sep 17 00:00:00 2001 From: Keqiao Zhang Date: Wed, 28 Sep 2022 10:03:43 +0800 Subject: [PATCH 7/7] hijack.sh: kill the mtrace after test need to kill the mtrace-reader.py process after the test to prevent the conflicts between each case. Signed-off-by: Keqiao Zhang --- case-lib/hijack.sh | 12 +++++++++++- 1 file changed, 11 insertions(+), 1 deletion(-) diff --git a/case-lib/hijack.sh b/case-lib/hijack.sh index 2c9986c9..c9d1c84e 100644 --- a/case-lib/hijack.sh +++ b/case-lib/hijack.sh @@ -24,7 +24,8 @@ function func_exit_handler() fi # when sof logger collect is open - if [ "X$SOF_LOG_COLLECT" == "X1" ]; then + # IPC4 is very different and handled below + if ! is_ipc4 && [ "X$SOF_LOG_COLLECT" == "X1" ]; then # when error occurs, exit and catch etrace log [[ $exit_status -eq 1 ]] && { func_lib_start_log_collect 1 @@ -100,6 +101,15 @@ function func_exit_handler() fi + if is_ipc4 && is_firmware_file_zephyr; then + local mtraceBin; mtraceBin=mtrace-reader.py + dlogi "pkill -TERM -f $mtraceBin" + sudo pkill -TERM -f "$mtraceBin" || { + dloge "mtrace-reader.py was already dead" + exit_status=1 + } + fi + stop_test || exit_status=1 if [ "$ENABLE_STORAGE_CHECKS" = '1' ]; then