Commit 1ef9f066 authored by Matt Hart's avatar Matt Hart Committed by Guillaume Tucker
Browse files

Use /dev/kmsg for LAVA test signals, if requested

Adds a parameter "lava-signal" to the test definition parameters
which when set to "kmsg" will tell the lava test scripts to echo
their output to /dev/kmsg.
This *might* help with test cases that produce kernel output and
can interrupt LAVA signals sent to stdout.

This review does NOT cover the issue that lava-test-runner signals
will still only be sent to stdout.

Change-Id: I8ac92c725ac49e40847d1a54c13bef81030903fa
parent 5dfc6585
......@@ -208,6 +208,10 @@ kernel to reduce the number or frequency of its messages, but often
those messages are critical information when debugging a fault so this
is not a good solution for everybody.
.. index:: kernel messages - interleaving, serial corruption
.. _isolating_kernel_messages:
Isolating kernel messages from test output
==========================================
......@@ -239,6 +243,9 @@ with kernel message output.
LAVA supports using these multiple serial connections in a simple way,
avoiding the need for MultiNode complexity.
.. seealso:: :ref:`test_definition_kmsg` for a mitigation of the
interleaving problem if multiple UART support is not available.
.. _extra_serial_ports_modify_test_image:
Changes needed in the test image
......
device_type: qemu
job_name: QEMU using kernel messages
timeouts:
job:
minutes: 15
action:
minutes: 5
connection:
minutes: 2
priority: medium
visibility: public
context:
arch: amd64
metadata:
docs-source: kmsg-events
docs-filename: qemu-kmsg-events.yaml
actions:
- deploy:
timeout:
minutes: 5
to: tmpfs
images:
rootfs:
image_arg: -drive format=raw,file={rootfs}
url: https://images.validation.linaro.org/kvm/standard/stretch-2.img.gz
compression: gz
os: debian
- boot:
timeout:
minutes: 2
method: qemu
media: tmpfs
prompts: ["root@debian:"]
auto_login:
login_prompt: "login:"
username: root
- test:
timeout:
minutes: 5
definitions:
# this test definition will use /dev/kmsg
- repository: http://git.linaro.org/lava-team/lava-functional-tests.git
from: git
lava-signal: kmsg
path: lava-test-shell/smoke-tests-basic.yaml
name: smoke-tests
# this test definition will use stdout
- repository: https://git.linaro.org/lava-team/lava-functional-tests.git
from: git
path: lava-test-shell/single-node/singlenode03.yaml
name: singlenode-advanced
......@@ -178,3 +178,159 @@ LAVA regularly runs a set of test definitions to check for regressions and the
set is available for others to use as a template for their own tests::
* https://git.linaro.org/lava-team/lava-functional-tests.git
.. _test_definition_kmsg:
Using kernel messages in a test shell
*************************************
.. seealso:: :ref:`Simple test job flow <simple_job_flow>` for
background on serial corruption and interleaving of kernel
messages with test output. Also :ref:`isolating_kernel_messages`
for information on using multiple serial connections to prevent
such issues.
In situations where multiple serial ports are not available, there is
a possible mitigation to the problem of serial corruption of test shell
messages by kernel messages.
This is an example of the interleaving of kernel messages and test
shell messages:
.. code-block:: none
<LAVA_SIGNAL_ENDRUN 0_network[ 31.811978] ------------[ cut here ]------------
-inline 14658_3.[ 31.818261] WARNING: CPU: 4 PID: 2576 at /srv/oe/build/tmp-rpb-glibc/work-shared/hikey/kernel-source/include/net/sock.h:1703 af_alg_accept+0x1d8/0x208 [af_alg]
2.3.1>
<LAVA_TE[ 31.834094] Modules linked in: algif_hash af_alg smsc75xx usbnet adv7511 kirin_drm drm_kms_helper dw_drm_dsi drm fuse
Received signal: <ENDRUN> 0_network[ 31.811978] ------------[ cut here ]------------
-inline 14658_3.[ 31.818261] WARNING: CPU: 4 PID: 2576 at /srv/oe/build/tmp-rpb-glibc/work-shared/hikey/kernel-source/include/net/sock.h:1703 af_alg_accept+0x1d8/0x208 [af_alg]
2.3.1
Ending use of test pattern.
Ending test lava.0_network[ (31.811978]), duration 1.92
case: 0_network[
case_id: 875068
definition: lava
duration: 1.92
namespace: hikey-oe
path: None
repository: None
result: pass
revision: unspecified
uuid: 31.811978]
_on_endrun() takes exactly 3 arguments (20 given)
The expected signal would have been more like the another message
of this type in the same test job:
.. code-block:: none
<LAVA_SIGNAL_ENDRUN 1_kselftest 14658_3.2.3.5>
Received signal: <ENDRUN> 1_kselftest 14658_3.2.3.5
Ending use of test pattern.
Ending test lava.1_kselftest (14658_3.2.3.5), duration 0.00
case: 1_kselftest
case_id: 876176
commit_id: fd1f392f983803e7189e264dda22790c54950c8f
definition: lava
duration: 0.0057
namespace: hikey-oe
path: automated/linux/kselftest/kselftest.yaml
repository: git://git.linaro.org/qa/test-definitions.git
result: pass
revision: unspecified
uuid: 14658_3.2.3.5
<LAVA_TEST_RUNNER>: 1_kselftest exited with: 0
As described in :ref:`isolating kernel messages <simple_job_flow>` in
the section on Multiple serial port support, this happens because the
test shell message ``<LAVA_SIGNAL_ENDRUN 1_kselftest 14658_3.2.3.5>``
is sent to ``stdout``. If the message was sent to ``/dev/kmsg`` then
the kernel would take care of emitting the entire line **before** (or
just **after**) emitting the warning. The test shell message would
remain intact and processing could continue normally.
Syntax
======
Test writers can decide which test shell definitions need to use this
support and which continue to use ``stdout``.
.. literalinclude:: examples/test-jobs/qemu-kmsg-events.yaml
:language: yaml
:linenos:
:lines: 47-57
:emphasize-lines: 4
By specifying ``lava-signal: kmsg`` for the first test shell definition
in the test job submission example above, LAVA can output the test
shell messages to ``/dev/kmsg``, resulting in output like:
.. code-block:: none
[ 8.862986] <LAVA_SIGNAL_ENDRUN 0_smoke-tests 1998_1.2.3.1>
+ export TESTRUN_ID=1_singlenode-advanced
+ TESTRUN_ID=1_singlenode-advanced
+ cd /lava-1998/0/tests/1_singlenode-advanced
++ cat uuid
+ UUID=1998_1.2.3.5
+ set +x
<LAVA_SIGNAL_STARTRUN 1_singlenode-advanced 1998_1.2.3.5>
+ apt-get update -q
Received signal: <TESTCASE> TEST_CASE_ID=linux-linaro-ubuntu-lsb_release RESULT=fail
case: linux-linaro-ubuntu-lsb_release
case_id: 49920
definition: 0_smoke-tests
result: fail
Received signal: <ENDRUN> 0_smoke-tests 1998_1.2.3.1
.. note::
* The LAVA test shell messages are now prefixed with the kernel
message time stamp - this does not affect processing which is
restricted to the content betweent the ``<`` and ``>`` markers.
* The ``STARTRUN`` message is not sent to ``/dev/kmsg`` (see
:ref:`kmsg_signal_limitations`) and is still vulnerable to kernel
messages being interleaved.
* When describing ``stdout``, ``stderr`` is implicitly included.
* The ordering of messages in the output shows the inherent
latency in the message processing.
.. _kmsg_signal_limitations:
Limitations
===========
.. seealso:: If the limitations with this approach make it unsuitable,
:ref:`multiple_serial_support` is preferred, where available.
Login
-----
The login shell is not part of the LAVA test shell, it is the final
part of the boot sequence and the input/output of the login shell is
not under the control of LAVA. If kernel messages appear when the
device is attempting to read in the username or password or if a
message appears when the login shell is attempting to output the
prompt, then the parsing will still fail.
stdout
------
The problem of interleaving messages from multiple inputs onto a single
output has not gone away by sending the LAVA test shell messages to
``/dev/kmsg``. There is still only a single serial connection which
**must** be shared between all ``stdout`` output and all ``console``
output. Test shell operations which produce a lot of ``stdout`` and/or
``stderr`` output can still flood the serial connection and interrupt
kernel message lines.
Definitions
-----------
Not all LAVA test shell operations can be sent to ``/dev/kmsg`` - some
will go to ``stdout`` even if all test definitions are marked to use
``/dev/kmsg`` because the test shell runner script needs to be the same
for all definitions.
......@@ -23,6 +23,8 @@ For certain tests, the instructions can be included inline with the actions.
For more complex tests or to share test definitions across multiple devices,
environments and purposes, the test can use a repository of YAML files.
.. seealso:: :ref:`test_repos` and :ref:`test_definition_kmsg`.
.. _test_definition_yaml:
Writing a test definition YAML file
......
......@@ -1070,6 +1070,8 @@ class TestRunnerAction(TestOverlayAction):
if self.parameters['name'] == 'lava':
raise TestError('The "lava" test definition name is reserved.')
lava_signal = self.parameters.get('lava-signal', 'stdout')
testdef_levels = self.get_namespace_data(action=self.name, label=self.name, key='testdef_levels')
with open(filename, 'a') as runsh:
for line in content:
......@@ -1082,7 +1084,11 @@ class TestRunnerAction(TestOverlayAction):
action='uuid', label='runner_path', key=self.parameters['test_name']))
runsh.write('UUID=`cat uuid`\n')
runsh.write('set +x\n')
runsh.write('echo "<LAVA_SIGNAL_STARTRUN $TESTRUN_ID $UUID>"\n')
if lava_signal == 'kmsg':
runsh.write('export KMSG=true\n')
runsh.write('echo "<0><LAVA_SIGNAL_STARTRUN $TESTRUN_ID $UUID>" > /dev/kmsg\n')
else:
runsh.write('echo "<LAVA_SIGNAL_STARTRUN $TESTRUN_ID $UUID>"\n')
runsh.write('set -x\n')
steps = testdef.get('run', {}).get('steps', [])
for cmd in steps:
......@@ -1090,7 +1096,11 @@ class TestRunnerAction(TestOverlayAction):
cmd = re.sub(r'\$(\d+)\b', r'\\$\1', cmd)
runsh.write('%s\n' % cmd)
runsh.write('set +x\n')
runsh.write('echo "<LAVA_SIGNAL_ENDRUN $TESTRUN_ID $UUID>"\n')
if lava_signal == 'kmsg':
runsh.write('unset KMSG\n')
runsh.write('echo "<0><LAVA_SIGNAL_ENDRUN $TESTRUN_ID $UUID>" > /dev/kmsg\n')
else:
runsh.write('echo "<LAVA_SIGNAL_ENDRUN $TESTRUN_ID $UUID>"\n')
self.results = {
'uuid': self.test_uuid,
......
......@@ -170,8 +170,8 @@ class TestShellAction(TestAction):
def _reset_patterns(self):
# Extend the list of patterns when creating subclasses.
self.patterns = {
"exit": "<LAVA_TEST_RUNNER>: exiting",
"error": "<LAVA_TEST_RUNNER>: ([^ ]+) installer failed, skipping",
"exit": "<LAVA_TEST_RUNNER EXIT>",
"error": "<LAVA_TEST_RUNNER INSTALL_FAIL>",
"eof": pexpect.EOF,
"timeout": pexpect.TIMEOUT,
"signal": r"<LAVA_SIGNAL_(\S+) ([^>]+)>",
......@@ -243,7 +243,6 @@ class TestShellAction(TestAction):
"otherwise this is a bug which should be reported.")
self.logger.debug("Using %s" % lava_test_results_dir)
connection.sendline('ls -l %s/' % lava_test_results_dir, delay=self.character_delay)
if lava_test_sh_cmd:
connection.sendline('export SHELL=%s' % lava_test_sh_cmd, delay=self.character_delay)
......
signal ()
{
if [ -z ${KMSG} ]
then
echo "${1}"
else
echo "<0>${1}" > /dev/kmsg
fi
}
#NOTE the lava_test_shell_action fills in the proper interpreter path
# above during target deployment
. lava-common-functions
usage () {
echo "Usage: lava-test-case TEST_CASE_ID --shell cmds ..."
......@@ -17,12 +18,13 @@ if [ -z "$TEST_CASE_ID" ]; then
usage
exit 1
fi
if [ "$1" = "--shell" ]; then
shift
echo "<LAVA_SIGNAL_STARTTC $TEST_CASE_ID>"
signal "<LAVA_SIGNAL_STARTTC $TEST_CASE_ID>"
eval "$*"
rc=$?
echo "<LAVA_SIGNAL_ENDTC $TEST_CASE_ID>"
signal "<LAVA_SIGNAL_ENDTC $TEST_CASE_ID>"
if [ $rc -eq 0 ]; then
RESULT=pass
else
......@@ -80,9 +82,8 @@ if [ -n "${MEASUREMENT+x}" ]; then
fi
# signal the test case results
echo "<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=$TEST_CASE_ID$TCDATA>"
signal "<LAVA_SIGNAL_TESTCASE TEST_CASE_ID=$TEST_CASE_ID$TCDATA>"
# lava-test-case testname --shell false should report a fail as test result
# but not fail itself; hence don't honor 'rc' if we reach this, but exit 0
exit 0
#NOTE the lava_test_shell_action fills in the proper interpreter path
# above during target deployment
. lava-common-functions
feedback_usage () {
echo "Usage:"
......@@ -27,6 +28,6 @@ if [ -z "${NAMESPACE+x}" ]; then
exit 1
fi
echo "<LAVA_SIGNAL_TESTFEEDBACK $NAMESPACE>"
signal "<LAVA_SIGNAL_TESTFEEDBACK $NAMESPACE>"
exit 0
# Sends a message which raises a TestError
# using the specified message (which must exist)
. lava-common-functions
raise_usage () {
echo "Usage:"
......@@ -13,6 +14,6 @@ if [ -z "${1}" ]; then
exit 1
fi
echo "<LAVA_SIGNAL_TESTRAISE $@>"
signal "<LAVA_SIGNAL_TESTRAISE $@>"
# always fail
exit 1
#NOTE the lava_test_shell_action fills in the proper interpreter path
# above during target deployment
. lava-common-functions
reference_usage () {
echo "Usage:"
......@@ -43,5 +44,5 @@ if [ -z "${REFERENCE+x}" ]; then
exit 1
fi
echo "<LAVA_SIGNAL_TESTREFERENCE $TEST_CASE_ID $RESULT $REFERENCE>"
exit 0
\ No newline at end of file
signal "<LAVA_SIGNAL_TESTREFERENCE $TEST_CASE_ID $RESULT $REFERENCE>"
exit 0
#!/bin/sh
set +x
if [ "$1" = "" ]
then
LAVA_PATH="/lava"
......@@ -7,22 +9,19 @@ else
LAVA_PATH=$1
fi
echo $LAVA_PATH
PREFIX="<LAVA_TEST_RUNNER>:"
WORKFILE="$LAVA_PATH/lava-test-runner.conf"
RESULTSDIR="$LAVA_PATH/results"
BINDIR="$LAVA_PATH/../bin"
. $BINDIR/lava-common-functions
cleanup()
{
# just adds a little handy debugging
ls ${RESULTSDIR}
echo "${PREFIX} exiting lava-test-runner"
signal "<LAVA_TEST_RUNNER EXIT>"
}
trap cleanup INT TERM EXIT
export PATH=${BINDIR}:${PATH}
echo "${PREFIX} started"
mkdir -p ${RESULTSDIR}
# move the workfile to something timestamped and run that. This
......@@ -31,32 +30,24 @@ TS=`date +%s`
mv ${WORKFILE} ${WORKFILE}-${TS}
WORKFILE=${WORKFILE}-${TS}
echo "${PREFIX} looking for work in ${WORKFILE}"
if [ -z "${SHELL}" ]; then
SHELL=/bin/sh
fi
echo "${PREFIX} Using ${SHELL}"
for line in $(cat ${WORKFILE}); do
for line in $(cat ${WORKFILE} | grep -v LAVA_SIGNAL); do
test=`basename $line`
echo "${PREFIX} running ${test} under lava-test-shell..."
odir=${RESULTSDIR}/${test}-`date +%s`
mkdir ${odir}
cp ${line}/testdef.yaml ${odir}/
cp ${line}/testdef_metadata ${odir}/
if [ -f ${line}/install.sh ]; then
echo "${PREFIX} running ${test} installer ..."
/bin/sh ${line}/install.sh
R=$?
echo ${R} > ${odir}/install_return_code
if [ ${R} -ne 0 ] ; then
echo "${PREFIX} ${test} installer failed, skipping"
signal "<LAVA_TEST_RUNNER INSTALL_FAIL>"
continue
fi
fi
lava-test-shell --output_dir ${odir} ${SHELL} -e "${line}/run.sh"
echo "${PREFIX} ${test} exited with: `cat ${odir}/return_code`"
done
. lava-common-functions
set_usage () {
echo "Usage:"
echo " lava-test-set start NAME"
......@@ -7,12 +9,12 @@ set_usage () {
}
set_start () {
echo "<LAVA_SIGNAL_TESTSET START $1>"
signal "<LAVA_SIGNAL_TESTSET START $1>"
exit 0
}
set_stop () {
echo "<LAVA_SIGNAL_TESTSET STOP>"
signal "<LAVA_SIGNAL_TESTSET STOP>"
exit 0
}
......
......@@ -180,6 +180,7 @@ class TestDefinitionHandlers(StdoutTestCase): # pylint: disable=too-many-public
'lava-test-set',
'lava-test-shell',
'lava-test-raise',
'lava-common-functions'
]
overlay = None
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment