Drop the newlines serial workaround, it doesn't seem to fix things
enough of the time to be useful.
(From OE-Core rev: 6cd57b2d148c5de7839d52d8cec359e4a10e0cd6)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
If the BrokenPipeError occurs when writing to the serial port to wake it
up, defer the write and try again (which will happen on the 5s timeout
of the select call). Why it should return ESHUTDOWN and then work later
I'm not sure but it does appear to make it work. For now we need 'working'
QA tests whilst the issue is debugged.
(From OE-Core rev: ea9e6ba0ab31a0b20012c283aa768496a50b527a)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
If the console doesn't appear, breifly sleep and try an extra read. This
is a useful debugging trick which we may as well preserve in the code. We're
already failing at this point so extra data is useful.
This means if we perturb things on the other port, we may gain useful logging
insight.
(From OE-Core rev: be3724854947ded160789d0353b7efb8c593040f)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This disables Nagle's algorithm for our tcp serial connections which may
be causing data transfer issues.
(From OE-Core rev: f8eff4c427881a98333fdf7c42f66ed6603e4f03)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
We're struggling with the 6.5 kernel as the serial port getty doesn't appears sometimes
leading to failures in CI. Add a workaround of sending some newlines as a way of
unblocking the kernel/release issues whilst we try and work out how to get to the bottom
of the issue.
(From OE-Core rev: 0a65f0d272895ba13c8c133ee71f3605d765a8a7)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
In case utf-8 conversion of the serial console data is flaky
due to bad characters in the stream.
(From OE-Core rev: 3f4921ced1e2aae546ff7cef232eec3e214c28be)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
It is unclear when things fail which output was on which serial port. Improve the output
to show the last lines of both data to improve debugging.
(From OE-Core rev: 605938b3bb19dcf6c7218648b4d16df9eaa675fc)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
To aid debugging, always log the second serial console as well as the first
to a seperate log file. This should make it clearer what happened when we
see test failures.
(From OE-Core rev: 372cd58fe672726900af80f3e65a108984da2750)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Switch to the backslashreplace error handling when decoding strings so that
invalid characters are clear in the stream to improve debugging.
(From OE-Core rev: 8ec86d46f736ec3e625b741e97545377c79414ee)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
There is no point in decoding binary data only to encode it again risking
conversion issues. Write the raw data to the log file as binary and skip
the conversion.
Also always update self.msg even if a logfile isn't specified to improve
logging/debug.
(From OE-Core rev: b5d67471dddd198723c4f711747783a33e8e5987)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
The intent behind these functions was to dump the system state when issues occured
but it has never really worked as we'd planned. Regular monitoring as the build
runs has largely replaced this as that allows a trend to be seen rather than a spot
value which was never really useful. The code is bitrotting and not functioning
correctly so drop it.
[YOCTO #13872]
RP: Reword commit message
(From OE-Core rev: dea37ba49a236029da73d5cfbfc069bffc38b508)
Signed-off-by: Thomas Roos <throos@amazon.de>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
The error message is a little misleading as the qmp module is a
directory with __init__.py file, not qmp.py file. Also, put the
path where we try to import it from in the error message to make
the message more indicative.
(From OE-Core rev: 08bacbf797f6a50ae8abe8fc3455b3a15a0a94b3)
Signed-off-by: Chen Qi <Qi.Chen@windriver.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Complex boot sequences take a lot of time to reach serial console login.
In our case boot involves multiple bootloaders like u-boot and grub,
then hypervisors like xen, then initramfs images which do things like
validating secure boot and encrypting the main rootfs. All these happen
before main rootfs serial console login prompt is reached and thus many
things can go wrong, including race conditions, hangs and deadlocks, and
thus logging the details is important for development.
This change adds the qemu serial console logs to do_testimage task logs while
they are being read out. The logs are not added to bitbake output. This
enables debugging and tracing the do_testimage via task log file while the boot
and tests are running.
(From OE-Core rev: cb62fae6ea3e411643395b12e56c363ce4d73e5d)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
runqemu script works with qemu machines which provide login
and serial console to the qemu process stdout. Add the same support
to qemurunner so that testing with testimage.bbclass is possible.
Default qemu machines provide serial console boot logs and login via
socket to qemu process but I don't see a reason why qemu process stdout
should not be supported too since they work with runqemu as well.
(From OE-Core rev: a3d4b80c5b4cce933c759d023c75b8671c56fe12)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
* There is no need to be that precise. It just irritates in the logs.
* There is also no point in printing plain time.time() value a single
time while only using formatted printout everywhere else, thus remove
it.
* Use %d for printing integer times
(From OE-Core rev: f0988cb8cf8d03708490cca4eba345492ef78d52)
Signed-off-by: Enrico Jorns <ejo@pengutronix.de>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Since login user is configurable with boot_patterns['send_login_user'],
unconditionally using 'root' in the debug message can be confusing.
Also fix the debug message to say 'Logged in' instead of 'Logged'.
(From OE-Core rev: 900e3d42b918b5a33d8d952b3a8078fbe72ba98f)
Signed-off-by: Enrico Jorns <ejo@pengutronix.de>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Read from serial console with a small delay to bundle data to e.g.
full lines. Reading one character at a time is not needed and causes
busy looping.
(From OE-Core rev: 0049f6757f6f956fb4cc77b3df6a672c20b53cf4)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Luca Ceresoli <luca.ceresoli@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
When a qemu machine hangs, the QMP calls can hang for ever
too, and when this happens any failing test commands from ssh
runner may be followed by dump_monitor() calls which
then also hang. Hangs followed by hangs.
Use runqemutime at setup and run_monitor() specific timeout
for later calls.
(From OE-Core rev: 3a07bdf77dc6ecbf4c620b051dd032abaaf1e4ff)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Luca Ceresoli <luca.ceresoli@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Use a short sleep to bundle serial console reads so that
we are not reading one character at a time which reduces busy
looping.
(From OE-Core rev: cafe65d8cf7544edbd387f7f5f6d77c64c6b18fa)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Luca Ceresoli <luca.ceresoli@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This does not actually guarantee that the child runqemu process has completely exited:
poll() may return prematurely while the SIGTERM handler in runqemu is still running.
This thwarts the rest of the processing, and may terminate the handler before
it completes.
Use Popen.communicate() instead: this is what python documentation recommends as well:
https://docs.python.org/3/library/subprocess.html#subprocess.Popen.communicate
(From OE-Core rev: cd3e55606c427287f37585c5d7cde936471e52f4)
Signed-off-by: Alexander Kanavin <alex@linutronix.de>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Qemurunner should not pass rootfs to runqemu in case
rootfs is not a filesystem itself. Some images could
be built into some disk format like vmdk and this
commit makes qemurunner handle such images properly.
(From OE-Core rev: 5aea74046cf4c1aa7fa9e2402788d662268ccf53)
Signed-off-by: Sergei Zhmylev <s.zhmylev@yadro.com>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
By default host side IP address is not set and qemu listens
on all IP addresses on the host machine which is not a good
idea when images have root login enabled without password.
It make sense to listen only on localhost IP address 127.0.0.1 using
config change like:
QB_SLIRP_OPT = "-netdev user,id=net0,hostfwd=tcp:127.0.0.1:2222-:22"
This config works for qemu itself, but breaks runqemu which tries to
parse the host side port number from qemu process command line arguments.
So change the runqemu side hostfwd parsing for port number to ignore
the host IP address field.
Reviewed-by: Quentin Schulz <foss+yocto@0leil.net>
(From OE-Core rev: bdbd52082eb26f418000eb4e424baae9babc272c)
Signed-off-by: Mikko Rapeli <mikko.rapeli@linaro.org>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Using a binary string as the login banner search expression is fraught with
risks. We've seen cases on the autobuilder where "login:" is clearly shown
but the code hasn't triggered. The most likely cause is hidden control characters
in the output causing the search to fail.
Take the opportunity to remove the horrible binary string search, at the expense of
decoding the bootlog multiple times.
Tweak the logging so we can know which log was printed (self.msg or bootlog)
just in case this isn't the issue and we need more information in future.
(From OE-Core rev: 91b9e30e08695e715ef14c3df7471e8c99f9deb5)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Updates the log message printed when login banner is seen in QEMU to
report the UNIX Epoch time in addition to the human readable time. This
makes it much easier and accurate to correlate logs with the guest, in
particular with the guest journalctl which prints log timestamps in
human readable format and the oeqa SSH debug logging which prints the
UNIX Epoch.
(From OE-Core rev: 275b6f3c8d0eeafa3902c48a49655491a89c47bc)
Signed-off-by: Joshua Watt <JPEWhacker@gmail.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Upstream made changes to the qmp module. We need to use the legacy one
for now since that matches the interface we use, ultimately we likely
need to update our code.
Also fix the generic exception handler to show the actual exception
which helps debugging when something does break.
(From OE-Core rev: 6e90b0d909d3c8b1be5cb19f2411cd0e89735c84)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Add a comment explaining the non-obvious return codes.
(From OE-Core rev: 6572baffa02ba6b8a686490d55af17cacb528920)
Signed-off-by: Ross Burton <ross.burton@arm.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
sys.exit will cause finally statements and other code to run at exit. Since
we're using os.fork() here, os._exit() is apprioriate in this codepath.
(From OE-Core rev: ec08498ff29de9ccd23be88b9d7af3dab6bbb81e)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This is done when starting up qemu has failed, but is not done
when qemu started ok, but fails later in QMP communication.
Output from runqemu does contain valuable information to find out
why, so rather than fix all the QMP fails to include it, let's just
print it in stop().
(From OE-Core rev: 6e2bf68e4401db747484c2c8ba0f77500b1d2d49)
Signed-off-by: Alexander Kanavin <alex.kanavin@gmail.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Files in /proc/xxx/map_files/ may no longer exist, just ignore this rather than
raising an exception.
(From OE-Core rev: fb1027896a263cd91e2378a4e97dbdf0807b306b)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Add a couple of logging info to track time between activities, first
is from after the Popen(launch_cmd) to after qmp.connect(), second is
from qmp.connect() to the release of the qemu via the qmp("cont") command
this includes the mmap() activity.
Example output:
QMP connected to QEMU at 06/24/21 11:11:56 and took 0.9556229114532471 seconds from launch
QMP released QEMU at 06/24/21 11:11:56 and took 0.26789021492004395 seconds from connect
(From OE-Core rev: 547f49230ba4ebeefe5b696e0460ebaffa8e91e6)
Signed-off-by: Saul Wold <saul.wold@windriver.com>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This will allow for direct ssh connection without breaking
the first one that is used for monitoring. The "nowait" option
will cause qmp server connection to NOT block waiting.
(From OE-Core rev: 40f09e184afd42decf2f924896fef03beacddc4b)
Signed-off-by: Saul Wold <saul.wold@windriver.com>
Signed-off-by: Alexandre Belloni <alexandre.belloni@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
We now spend time copying the VM image into a tmpfs and with IO load on the
system, the time + the boot time of the VM can take longer than 120s. Increase
the timeout to match the added overhead of copying the image file.
(From OE-Core rev: a40087c966af5ffb9309e1ddfdb3d06973e0bddd)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
We've seeing issues where IO load appears to cause strange failures due to timeouts
within qemu. One theory for these is that it is is hitting hard page faults
at in-opportune moments which cause timing problems within the VM.
This patch is a bit of a hack which tries to ensure the data is paged in
at a point when we know we can take the time delays (waiting for the QMP
start signal). Whilst this isn't ideal, it does seem to improve things on
the autobuilder and shouldn't harm anything.
The code figures out which files to read my looking at the mmap'd files
the process has open from /proc. On Centos7 systems these files are not
user readable, if that is the case we just skip them.
(From OE-Core rev: e77844314d09ceff9c22338d366519928f4f7284)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
We had debugging for qemu faiing to start which was no longer reachable
after the QMP changes. Reorder the code to enable this debugging to work
again which may allow insight into autobuilder failures in this area.
(From OE-Core rev: 8fac8c61565977c775d8ede5bddc856b7767a3e4)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
When running a shutdown command, the serial port can close without the
command returning. This is seen as the socket being readable but having
no data. Change the way this case is handled in the code to avoid
tracebacks.
(From OE-Core rev: 396a3ba884820d040c91f7592daf20ac28c49b5d)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
The recent logging changes for qemurunner showed up as errors on the
autobuilder where decode couldn't be called on the returned string.
Since the code returns binary data, return b'' instead of '' to match
to avoid tracebacks.
One of these cases was newly added, copied from the other which has
been there for a long time, always broken.
(From OE-Core rev: b8995b27db265b0a0b2d2ca595915f70f9f96e07)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This information is useful, but should not be a warning level.
[YOCTO #14382]
(From OE-Core rev: cd17d8bb00be1ecb7c92ab13eb8b162807aefed9)
Signed-off-by: Saul Wold <saul.wold@windriver.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
After the addition of the qmp socket, runqemu started failing:
ERROR - Failed to run qemu: qemu-system-aarch64: -qmp unix:/home/yocto/actions-runner-meta-openembedded/_work/meta-openembedded/meta-openembedded/yoe/build/tmp/.3eg5fiid,server,wait:
UNIX socket path '/home/yocto/actions-runner-meta-openembedded/_work/meta-openembedded/meta-openembedded/yoe/build/tmp/.3eg5fiid' is too long
Path must be less than 108 bytes
To avoid this, run qemu within tmpdir and use a relative path to the socket.
This avoids having to patch the socket code within qemu.
Update the client code to chdir and only use a relative path to the socket
to match.
(From OE-Core rev: 5c56e72fca18dc942f5c1fd377e98d46ae0126f1)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Rather than totally disabling the logging, inform it we're about to exit
so we can log messages over the exit cleanly too. This aids debugging. It
also avoids a race where the logging handler could still error whilst
shutting down.
Also remove a race window by notificing the handler of the shutdown
first, before triggering it. This removes a race window I watched in
local testing.
(From OE-Core rev: 0e19f31a1005f94105e1cef252abfffcef2aafad)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This adds support for the Qemu Machine Protocol [0] extending
the current dump process for Host and Target. The commands are
added in the testimage.bbclass.
Currently, we setup qemu to stall until qmp gets connected and
sends the initialization and continue commands, this works
correctly. If the UNIX Socket does not exist, we wait an timeout
to ensure to socket file is created.
With this version, the monitor_dumper is created in OEQemuTarget
but then set in OESSHTarget as that's where we get the SSH failure
happens. Python's @property is used to create a setter/getter type
of setup in OESSHTarget to get overridden by OEQemuTarget.
By default the data is currently dumped to files for each command in
TMPDIR/log/runtime-hostdump/<date>_qmp/unknown_<seq>_qemu_monitor as
this is the naming convenstion in the dump.py code.
We use the qmp.py from qemu, which needs to get installed in the
recipe-sysroot-native of the target image.
[0] https://github.com/qemu/qemu/blob/master/docs/interop/qmp-spec.txt
(From OE-Core rev: 42af4cd2df72fc8ed9deb3fde4312909842fcf91)
Signed-off-by: Saul Wold <saul.wold@windriver.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
We have a working theory that IO queues on the autobuilder are impacting
runtime testing under qemu, particularly async writes which inice does not
influence. We already pass the snapshot option to qemu which copies the
image and runs out of the copy. Add in the ability to copy the image to
a specificed location which can be a tmpfs. This means that writes to the
image would no longer be blocked by other writes to disk in the system.
Preliminary tests show that this does improve the qemu errors at the expense
of sometimes showing qemu startup timeouts as on a loaded system with a large
test image, it can take longer than 120s to copy the image to tmpfs. Having
a most consistent failure mode for loaded tests is probably desireable though.
(From OE-Core rev: fd1c26ab426c3699ffd8082b83d65a84c8eb8bff)
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Richard Purdie
Mikko Rapeli
Thomas Roos
Chen Qi
Enrico Jörns
Alexander Kanavin
Sergei Zhmylev
Ross Burton
Joshua Watt
Saul Wold