Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 8 additions & 1 deletion case-lib/lib.sh
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ fi
func_lib_setup_kernel_checkpoint()
{
# shellcheck disable=SC2034 # external script will use it
KERNEL_CHECKPOINT=$(wc -l /var/log/kern.log|awk '{print $1;}')
KERNEL_CHECKPOINT=$(date +%s)
}

# This function adds a fake error to dmesg (which is always saved by
Expand Down Expand Up @@ -311,3 +311,10 @@ is_sof_used()
{
grep -q "sof" /proc/asound/cards;
}

# a wrapper to journalctl with required style
journalctl_cmd()
{
journalctl -k -q --no-pager --utc --output=short-monotonic \
--no-hostname "$@"
}
22 changes: 8 additions & 14 deletions test-case/verify-sof-firmware-load.sh
Original file line number Diff line number Diff line change
Expand Up @@ -20,13 +20,11 @@ source "$(dirname "${BASH_SOURCE[0]}")"/../case-lib/lib.sh

func_opt_parse_option "$@"

if ! alias | grep -q 'Sub-Test'; then
# hijack DMESG_LOG_START_LINE which refer dump kernel log in exit function
DMESG_LOG_START_LINE=$(sof-get-kernel-line.sh|tail -n 1 |awk '{print $1;}')
cmd="sof-kernel-dump.sh"
else
cmd="journalctl --dmesg --no-pager"
fi
# hijack DMESG_LOG_START_LINE to dump kernel from file start is not Sub-Test
# TODO: clean up Sub-Test feature
alias | grep -q 'Sub-Test' || DMESG_LOG_START_LINE=$(sof-get-kernel-line.sh | tail -n 1 | awk '{print $1;}' )

cmd="journalctl_cmd"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not 100% sure this has to be in the same PR than the rest.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I named this PR as use journalctl as default kernel log reader, so I think put all change there is OK.
I split them into different commit. If you want single commit in one PR I am OK with that.


dlogi "Checking SOF Firmware load info in kernel log"
if $cmd | grep -q " sof-audio.*Firmware.*version"; then
Expand All @@ -36,12 +34,8 @@ if $cmd | grep -q " sof-audio.*Firmware.*version"; then
$cmd | grep "Firmware debug build" -A3 | head -n 12
exit 0
else
printf ' ------\n debuging with /var/log/kern.log \n ---- \n'
ls -alht /var/log/kern.log
grep -na "Linux version" /var/log/kern.log || true
printf ' ------\n cmd was %s, DMESG_LOG_START_LINE was %s \n ---- \n' \
"$cmd" "$DMESG_LOG_START_LINE"
journalctl --dmesg --lines 50 --no-pager
journalctl --dmesg | grep -C 1 " sof-audio.*Firmware.*version" || true
journalctl_cmd --lines 50 || true
printf ' ------\n debugging with systemd journalctl \n ---- \n'
systemctl status systemd-journald* || true
die "Cannot find the sof audio version"
fi
20 changes: 9 additions & 11 deletions tools/sof-get-default-tplg.sh
Original file line number Diff line number Diff line change
@@ -1,14 +1,12 @@
#!/bin/bash
#
# read kernel log to get topology file loaded by SOF driver
# Example from an apl up2 pcm512x device:
#
# sof-audio-pci 0000:00:0e.0: loading topology:intel/sof-tplg/sof-apl-pcm512x.tplg
#
# sof-apl-pcm512x.tplg will be returned
#

# Current: load TPLG file order:
# dmesg
# journalctl
# /var/log/syslog (sof-kernel-dump.sh)
# Future: possibly be loaded from elsewhere
# Notice: Only verified on Ubuntu 18.04
tplg_file=$(dmesg |grep -i topology|awk -F ':' '/tplg/ {print $NF;}'|tail -n 1)
[[ ! "$tplg_file" ]] && \
tplg_file=$(journalctl -k |grep -i topology |awk -F ':' '/tplg/ {print $NF;}'|tail -n 1)
[[ ! "$tplg_file" ]] && \
tplg_file=$(sof-kernel-dump.sh |grep -i topology|awk -F ':' '/tplg/ {print $NF;}'|tail -n 1)
tplg_file=$(journalctl -k |grep -i topology |awk -F ':' '/tplg/ {print $NF;}'|tail -n 1)
[[ "$tplg_file" ]] && basename "$tplg_file" || echo ""
39 changes: 16 additions & 23 deletions tools/sof-kernel-log-check.sh
Original file line number Diff line number Diff line change
Expand Up @@ -126,11 +126,14 @@
# Append some garbage to an ignore pattern to turn it off. Much easier
# than deleting it.


begin_line=${1:-1}
# fallback to use dmseg when set to 0.
# TODO: update the fallback option when drop dmesg
begin_timestamp=${1:-0}
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I already submitted this in September in PR #366 but something was wrong at the time. Is it OK now and why?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because I drop the usage for line number now. And with my comments below
# confirm begin_timestamp is in UNIX timestamp format, otherwise use dmesg

We will always fallback to use demsg if no checkpoint is provided or wrong format checkpoint is provided

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We will always fallback to use demsg if no checkpoint is provided or wrong format checkpoint is provided

The only user of this script is ourselves, so to reduce complexity a lot let's just fix the user instead of providing a fallback. Fail here when some test does not provide a valid checkpoint and then calls this script, which seems very wrong!? Let's fix all these broken tests and make them consistent before switching the checkpoint to journalctl

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I thought we have an agreement in #468 (comment)

@marc-hb Thanks for the tips, I am also think about how to spilt the patches. Please help to check my plan:

  1. replace LINE with TIMESTAMP, log check with no --priority but still with err_str
  2. quoting clean up for the $KERNEL_LAST_TIMESTAMP
  3. remove err_str and use --priority, add new ignore_str
  4. clean up test case to remove duplicate kernel log check.

Now we have done half of the step 1 by changing the LINE into CHECKPOINT in #499. Now I am not sure if I can do clean up in step 4 before we change to use journalctl with use --priority, it would bring more unrelated error in our test now.

Or we can do something more simpler, merge a big PR #468 I have already made and tested and fix bugs if we find any.

Any suggestions here @marc-hb @aiChaoSONG @plbossart @mengdonglin
I am not sure what we are reviewing here. I do not see any feedback about codes or implementation. I only see how to spilt patches. For such big implementation change, I am not sure if small steps can make thing easier because I need to do some un-needed migration clean up for each small change. EG: @marc-hb The fallback here is one of those things I do not need to have in big PR. But I have to keep it here for migration.

If we do not make progress before my vacation next week. I will use my super power to merge all the change in one PR.

declare err_str ignore_str

platform=$(sof-dump-status.py -p)
# pwd resolves relative paths
my_dir=$(cd "$(dirname "${BASH_SOURCE[0]}")" && pwd)
platform=$("$my_dir"/sof-dump-status.py -p)

err_str="error|failed|timed out|panic|oops"

Expand Down Expand Up @@ -250,32 +253,22 @@ case "$platform" in
;;
esac

[[ ! "$err_str" ]] && echo "Missing error keyword list" && exit 0
# dmesg KB size buffer size
#dmesg_config_define=$(awk -F '=' '/CONFIG_LOG_BUF_SHIFT/ {print $2;}' /boot/config-$(uname -r))
#dmesg_buffer_size=$( echo $(( (1<<$dmesg_config_define) / 1024 )) )
# kernel file log buffer size
#kernel_buffer_size=$(du -k /var/log/kern.log |awk '{print $1;}')
# now decide using which to catch the kernel log
#[[ $kernel_buffer_size -lt $dmesg ]] && cmd="dmesg" || cmd="tail -n +${begin_line} /var/log/kern.log"

# confirm begin_line is number, if it is not the number, direct using dmesg
[[ "${begin_line//[0-9]/}" ]] && begin_line=0
[[ "$begin_line" -eq 0 ]] && cmd="dmesg" || cmd="tail -n +${begin_line} /var/log/kern.log"
# confirm begin_timestamp is in UNIX timestamp format, otherwise use dmesg
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please add a comment explaining why we still need to support a different begin_timestamp format.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do not think we need a different begin_timestamp format. What I mean here is to keep the fallback we used to have to dmesg now to cover the small migration steps.

# TODO: drop dmesg usage as fallback and use no --since as fallback
journalctlflag="-k -q --no-pager --utc --output=short-iso --no-hostname"
[[ $begin_timestamp =~ ^[0-9]{10} ]] && cmd="journalctl $journalctlflag --since=@$begin_timestamp" || cmd="dmesg"
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Why stick to dmesg? Its output looks very different. Why not just drop the --since= parameter?

Copy link
Contributor Author

@xiulipan xiulipan Nov 18, 2020

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@marc-hb We need to keep dmesg as some user still use dmesg way.
I had following patches to drop the dmesg, see #468
commits like 8db6f8c


#echo "run $0 with parameter '$*' for check kernel message error"

# declare -p cmd
declare -p cmd
if [ "$ignore_str" ]; then
err=$( $cmd | grep 'Call Trace' -A5 -B3)$( $cmd | grep -E "$err_str"|grep -vE "$ignore_str")
err=$($cmd | grep 'Call Trace' -A5 -B3)$($cmd | grep -E "$err_str"|grep -vE "$ignore_str")
else
err=$( $cmd | grep 'Call Trace' -A5 -B3)$( $cmd | grep -E "$err_str")
err=$($cmd | grep 'Call Trace' -A5 -B3)$($cmd | grep -E "$err_str")
fi

if [ "$err" ]; then
echo "$(date -u '+%Y-%m-%d %T %Z')" "[ERROR]" "Caught dmesg error"
[[ -z "$err" ]] || {
echo "$(date -u '+%Y-%m-%d %T %Z')" "[ERROR]" "Caught kernel log error"
echo "===========================>>"
echo "$err"
echo "<<==========================="
builtin exit 1
fi
}