Combining stdout/stderr in the result can lead to problems when e.g.
the stdout of a task is used as an input for another task.
This is also different from the normal Ansible behavior and can be
surprising and hard to debug for users.
The new behavior is configurable and off by default to retain backward
compatibility.
Change-Id: Icaced970650913f9632a8db75a5970a38d3a6bc4
Co-Authored-By: James E. Blair <jim@acmegating.com>
When a user sets zuul_console_disabled, we don't need to try to
connect to the streaming daemon. In fact, they may have set it
because they know it won't be running. Check for this and avoid
the connection step in that case and therefore avoid the extraneous
"Waiting on logger" messages and extra 30 second delay at the end
of each task.
Change-Id: I86af231f1ca1c5b54b21daae29387a8798190a58
Upon further discussion we recently found another case of leaking
console streaming files; if the zuul_console is not running on port
19885, or can not be reached, the streaming spool files will still be
leaked.
The prior work in I823156dc2bcae91bd6d9770bd1520aa55ad875b4 has the
receiving side indicate to the zuul_console daemon that it should
remove the spool file.
If this doesn't happen, either because the daemon was never there, or
it is firewalled off, the streaming spool files are left behind.
This modifies the command action plugin to look for a variable
"zuul_console_disable" which will indicate to the library running the
shell/command task not to write out the spool file at all, as it will
not be consumed.
It is expected this would be set at a host level in inventory for
nodes that you know can not or will not have access to zuul_console
daemon.
We already have a mechanism to disable this for commands running in a
loop; we expand this with a new string type. The advantage of this is
it leaves the library/command.py side basically untouched.
Documentation is updated, and we cover this with a new test.
Change-Id: I0273993c3ece4363098e4bf30bfc4308bb69a8b4
This is a follow-on to Ia78ad9e3ec51bc47bf68c9ff38c0fcd16ba2e728 to
use a different loopback address for the local connection to the
Python 2.7 container. This way, we don't have to override the
existing localhost/127.0.0.1 matches that avoid the executor trying to
talk to a zuul_console daemon. These bits are removed.
The comment around the port settings is updated while we're here.
Change-Id: I33b2198baba13ea348052e998b1a5a362c165479
Change Ief366c092e05fb88351782f6d9cd280bfae96237 intoduced a bug in
the streaming daemons because it was using Python 3.6 features. The
streaming console needs to work on all Ansible managed nodes, which
includes back to Python 2.7 nodes (while Ansible supports that).
This introduces a regression test by building about the smallest
Python 2.7 container that can be managed by Ansbile. We start this
container and modify the test inventory to include it, then run the
stream tests against it.
The existing testing runs against the "new" console but also tests
against the console OpenDev's Zuul starts to ensure
backwards-compatability. Since this container wasn't started by Zuul
it doesn't have this, so that testing is skipped for this node.
It might be good to abstract all testing of the console daemons into
separate containers for each Ansible supported managed-node Python
version -- it's a bit more work than I want to take on right now.
This should ensure the lower-bound though and prevent regressions for
older platforms.
Change-Id: Ia78ad9e3ec51bc47bf68c9ff38c0fcd16ba2e728
With the defaulh "linear" strategy (and likely others), Ansible will
send the on_task_start callback, and then fork a worker process to
execute that task. Since we spawn a thread in the on_task_start
callback, we can end up emitting a log message in this method while
Ansible is forking. If a forked process inherits a Python file object
(i.e., stdout) that is locked by a thread that doesn't exist in the
fork (i.e., this one), it can deadlock when trying to flush the file
object. To minimize the chances of that happening, we should avoid
using _display outside the main thread.
The Python logging module is supposed to use internal locks which are
automatically aqcuired and released across a fork. Assuming this is
(still) true and functioning correctly, we should be okay to issue
our Python logging module calls at any time. If there is a fault
in this system, however, it could have a potential to cause a similar
problem.
If we can convince the Ansible maintainers to lock _display across
forks, we may be able to revert this change in the future.
Change-Id: Ifc6b835c151539e6209284728ccad467bef8be6f
This is a small refactor to check the output of each node separately.
This should have no effect, but makes it easier to add more testing in
a follow-on change.
Change-Id: Ic5d490c54da968b23fed068253f5be0249ea953a
When using protocol version 1, send a finalise message when streaming
is complete so that the zuul_console daemon can delete the temporary
file.
We test this by inspecting the Ansible console output, which logs a
message with the UUID of the streaming job. We dump the temporary
files on the remote side and make sure a console file for that job
isn't present.
Change-Id: I823156dc2bcae91bd6d9770bd1520aa55ad875b4
A refresher on how this works, to the best of my knowledge
1 Firstly, Zuul's Ansible has a library task "zuul_console:" which is
run against the remote node; this forks a console daemon, listening
on a default port.
2 We have a action plugin that runs for each task, and if that task
is a command/shell task, assigns it a unique id
3 We then override with library/command.py (which backs command/shell
tasks) with a version that forks and runs the process on the target
node as usual, but also saves the stdout/stderr output to a
temporary file named per the unique uuid from the step above.
4 At the same time we have the callback plugin zuul_stream.py, which
Ansible is calling as it moves through starting, running and
finishing the tasks. This looks at the task, and if it has a UUID
[2], sends a request to the zuul_console [1], which opens the
temporary file [3] and starts streaming it back.
5 We loop reading this until the connection is closed by [1],
eventually outputting each line.
In this way, the console log is effectively streamed and saved into
our job output.
We have established that we expect the console [1] is updated
asynchronously to the command/streaming [3,4] in situation such as
static nodes. This poses a problem if we ever want to update either
part -- for example we can not change the file-name that the
command.py file logs to, because an old zuul_console: will not know to
open the new file. You could imagine other fantasy things you might
like to do; e.g. negotiate compression etc. that would have similar
issues.
To provide the flexibility for these types of changes, implement a
simple protocol where the zuul_stream and zuul_console sides exchange
their respective version numbers before sending the log files. This
way they can both decide what operations are compatible both ways.
Luckily the extant protocol, which is really just sending a plain
uuid, can be adapted to this. When an old zuul_console server gets
the protocol request it will just look like an invalid log file, which
zuul_stream can handle and thus assume the remote end doesn't know
about protocols.
This bumps the testing timeout; it seems that the extra calls make for
random failures. The failures are random and not in the same place,
I've run this separately in 850719 several times and not seen any
problems with the higher timeout. This test is already has a settle
timeout slightly higher so I think it must have just been on the edge.
Change-Id: Ief366c092e05fb88351782f6d9cd280bfae96237
The zuul-stream-functional tests currently run Ansible against two
hosts (node1 and node2) started by the "infrastructure" Zuul. However
the tests are working with the zuul_console running on the default
port 19885 -- which is the zuul_console started by the setup jobs at
[1].
The result of this is that this test is only talking to a zuul_console
instance started from the current executor's code, not the Zuul
checkout uder test -- i.e. changes to zuul_console.py aren't tested by
this change.
This modifies the job playbook to have another step that can start its
own zuul_console service on the two hosts running at another port
(19887). This way we can test against the zuul_console code from the
Zuul checkout. A new step is added to run a playbook overriding to
this port.
We retain the existing test (against the already running port 19885)
as a backwards compatability test; although we don't exactly know what
this is running (as it comes from OpenDev's production executors) we
want changes to the console log/stream callback to be able to run
against it, as it may represent what is running a static node.
The test results are pulled apart a bit to be more explicit, logging
and testing each run separately.
[1] https://opendev.org/zuul/zuul-jobs/src/branch/master/roles/prepare-workspace/tasks/main.yaml#L2
Change-Id: Ib11b77cfdc6c59d12807c6d9684c3e653ccad863
This adds python3.10 testing on Jammy and switches the docker images to
python3.10 from 3.8.
We run sudo for postgres with -Hi to avoid non fatal errors when
postres' client attempts to write command history to Zuul's homedir (it
is running as the postgres user which can't write to zuul's homedir). We
also need to update the libffi package version for jammy to 8 in
bindep.txt. Finally, python_version values need to be quoted as "3.10"
is different than 3.10 which is equivalent to 3.1 when serialized by
yaml as a float.
Force setuptools to use stdlib (shipped by the distro) distutils to
avoid problems with virtualenvs not actually being virtualenvs.
Finally we switch the bulk of jobs over to using nodeset: ubuntu-jammy
as the default python there is 3.10.
Change-Id: I97b90bb7a23c90f108f23dda9fdd0e89f9f4dbca
A couple of locations continue to reference actiongeneral which has been
removed. Update these locations to use action as the current location
for these plugins.
Change-Id: I71c03d2c0a84592be66fa0d84bc684684a392a27
This adds support for Ansible 5. As mentioned in the reno, only
the major version is specified; that corresponds to major.minor in
Ansible core, so is approximately equivalent to our current regime.
The command module is updated to be based on the current code in
ansible core 2.12.4 (corresponding to community 5.6.0). The previous
version is un-symlinked and copied to the 2.8 and 2.8 directories
for easy deletion as they age out.
The new command module has corrected a code path we used to test
that the zuul_stream module handles python exceptions in modules,
so instead we now take advantage of the ability to load
playbook-adjacent modules to add a test fixture module that always
raises an exception. The zuul stream functional test validation is
adjusted to match the new values.
Similarly, in test_command in the remote tests, we relied on that
behavior, but there is already a test for module exceptions in
test_module_exception, so that check is simply removed.
Among our Ansible version tests, we occasionally had tests which
exercised 2.8 but not 2.9 because it is the default and is otherwise
tested. This change adds explicit tests for 2.9 even if they are
redundant in order to make future Ansible version updates easier and
more mechanical (we don't need to remember to add 2.9 later when
we change the default).
This is our first version of Ansible where the value of
job.ansible-version could be interpreted as an integer, so the
configloader is updated to handle that possibility transparently,
as it already does for floating point values.
Change-Id: I694b979077d7944b4b365dbd8c72aba3f9807329
This has been pinned to a very old version of ARA for some time, and
newer versions of Ansible are no longer compatible with the old version
of ARA. Since this isn't receiving maintenance keeping it up to date,
remove it.
Note that if there is desire for support for this or other callback
plugins, it would be quite reasonable and relatively straightforward
to add the ability to generically configure additional callback plugins.
This would have the advantage of not requiring tight internal integration
between Zuul and other callback plugins. Such a change would likely
be welcome.
Change-Id: I733e48127f2b1cf7d2d52153844098163e48bae8
New versions of git refuse to run on git repos owned by a user
other than the caller. This is due to a fix for
https://cve.mitre.org/cgi-bin/cvename.cgi?name=CVE-2022-24765
The stream jobs install Zuul as root while the repo is owned by
zuul. This causes pbr to run git which runs afoul of that issue.
To correct this, run a wheel build as the zuul user first and
install the wheel.
Change-Id: Id48245f715760c436ae46415f057358e1b687181
We were running on Bionic because Zuul's inclusion of a pinned Gear
conflicted with TLS policy on Focal. With Gear gone we can bump up to
Focal safely now.
Followup changes can bump testing platforms ahead to 3.9 or newer as
well.
Change-Id: I4cfef79ebc97753994edaf36a1deca0d3b37ad17
We dropped installing ARA here when
I5ce1385245c76818777aa34230786a9dbaf723e5 converting things to using
the Zuul managed versions of Ansible (which installs ARA). Since we
dropped the required-projects, I think the bindep here has been
silently just not doing anything.
We also stop gzipping the output -- it makes it fairly useless as
you'd have to bulk download the whole thing to unzip it. I think this
was an artifact of the old logs.openstack.org days.
Needed-By: https://review.opendev.org/c/openstack/project-config/+/777675
Change-Id: I727a088c3176d13b483a0c28f39cbc0f51dad3f6
The new cryptography release needs either a recent pip to be able to
use abi3 wheels or a rust compiler on the system to make the source
installation work. Thus upgrade pip to use the wheels.
Change-Id: Ied6007f9f834f313063e2e56a057a7082a71e5c4
Zuul now requires at least python 3.6 so use the bionic image for the
zuul-stream-functional tests as well.
Change-Id: Iba47cd9733e97fba5b0471fdcfc69588f03f85d9
Zuul was designed to block local code execution in untrusted
environments to not only rely on bwrap to contain a job. This got
broken since the creation of a command plugin that injects the
zuul_job_id which is required for log streaming. However this plugin
doesn't do a check if the task is a localhost task. Further it is
required in trusted and untrusted environments due to log
streaming. Thus we need to fork this plugin and restrict the variant
that is used in untrusted environments.
We do this by moving actiongeneral/command.py back to action/*. We
further introduce a new catecory actiontrusted which gets the
unrestricted version of this plugin.
Change-Id: If81cc46bcae466f4c071badf09a8a88469ae6779
Story: 2007935
Task: 40391
virtualenv 20.0.24 creates ~/.local/share/virtualenv with the
seed packages needed for making virtualenvs per-python version.
Creating empty virtualenvs is quick, so run those in sequence
to avoid race possibilities. Then, we can still run the
installs into the virtualenvs in parallel.
We also fix a bug in the console stream functional jobs and install pip
with the use of ensure-pip. This is necessary because the virtualenv
fix runs the stream functional jobs and the update to the stream
functional jobs relies on working docker images.
Change-Id: I3dec251d19dd7b3807848a54e6a20a8e89d30a4e
The pre.yaml playbook for the zuul-stream-functional tests copies
the Ansible inventory.yaml file from the executor to the test
"controller" node. The controller then runs the specified version
of Ansible 2.x against the other nodes. This fails because the
executor version of inventory.yaml contains "auto" for the Ansible
python interpreter which is valid under the version of Ansible used
on the executor, but on the controller node, which runs the older
versions of Ansible, this is *not* a valid value. Thus it fails.
This change forces the executor to use the version of Ansible being
tested on the controller so that the inventory.yaml will be correct.
Also, Ansible 2.8 now throws a FileNotFoundError exception instead
of OSError when a referenced file is not found.
Change-Id: Ibd31f1161df0076ed7498fd1d7b1ae76c802c6e4
As a first step towards supporting multiple ansible versions we need
tooling to manage ansible installations. This moves the installation
of ansible from the requirements.txt into zuul. This is called as a
setup hook to install the ansible versions into
<prefix>/lib/zuul/ansible. Further this tooling abstracts knowledge
that the executor must know in order to actually run the correct
version of ansible.
The actual usage of multiple ansible versions will be done in
follow-ups.
For better maintainability the ansible plugins live in
zuul/ansible/base where plugins can be kept in different versions if
necessary. For each supported ansible version there is a specific
folder that symlinks the according plugins.
Change-Id: I5ce1385245c76818777aa34230786a9dbaf723e5
Depends-On: https://review.openstack.org/623927
According to the docs ansible is expected to return 3 if there were
unreachable nodes. Zuul reacts on this and retries the job. However
ansible really returns 4 in this case [1] which actually is the code
for a parse error (which doesn't make sense to retry).
To work around that add a simple callback plugin that gets notified if
there are unreachable nodes and write the information about which
nodes failed to a special file beneath the job-output.txt. The
executor can detect this and react properly then. Further we have the
information about which nodes failed in this file which gets uploaded
to the log server too if it exists.
[1] https://github.com/ansible/ansible/issues/19720
Change-Id: I6d609835dba18b50dcbe883d01c6229ce4e38d91
Some deployment methods require an __init__.py file in every directory
containing python files. However action-general is no valid package
name so we need to rename that.
Change-Id: If15b0a6166538debc52df41c06767978ef183b05
The log streaming callback is not being called in the same way
in Ansible 2.5 as it was in 2.3. In particular, in some cases
different Task objects are used for different hosts. This,
combined with the fact that the callback is only called once for
a given task means that in these cases we are unable to supply
the zuul_log_id to the Task object for the second host on a task.
This can be resolved by injecting the zuul_log_id within the command
action plugin based on the task uuid directly.
Change-Id: I7ff35263c52d93aeabe915532230964994c30850
Squashed changes:
- Use 'inventory' instead of 'hostfile' in ansible.cfg.
'hostfile' is deprecated.
- Use 'os.environ.copy()' in zuul_return.py since this causes 2.4 to
throw an exception now deep within module.exit_json().
Change-Id: I0a52c9e169a54d24a7b361010045fb10211418b7
The log stream is read in chunked blocks. When having multi byte
unicode characters in the log stream it can happen that this character
is split into different buffers. This can break the decode step with
an exception [1]. This can be fixed by treating the buffer as binary
and decoding the final lines.
Further we must expect that the data also contains binary data. In
order to cope with this further harden the final decoding by adding
'backslashreplace'. This will replace every occurrence of an
undecodable character by an appropriate escape sequence. This way we
can retain all the information (even binary) without being unable to
decode the stream.
[1]: Log output
Ansible output: b'Exception in thread Thread-10:'
Ansible output: b'Traceback (most recent call last):'
Ansible output: b' File "/usr/lib/python3.5/threading.py", line 914, in _bootstrap_inner'
Ansible output: b' self.run()'
Ansible output: b' File "/usr/lib/python3.5/threading.py", line 862, in run'
Ansible output: b' self._target(*self._args, **self._kwargs)'
Ansible output: b' File "/var/lib/zuul/ansible/zuul/ansible/callback/zuul_stream.py", line 140, in _read_log'
Ansible output: b' more = s.recv(4096).decode("utf-8")'
Ansible output: b"UnicodeDecodeError: 'utf-8' codec can't decode bytes in position 4094-4095: unexpected end of data"
Ansible output: b''
Change-Id: I568ede2a2a4a64fd3a98480cebcbc2e86c54a2cf
Logs may have whitespace prefixing used to properly left align content.
Preserve this and only strip trailing whitespace from the logs. Also to
simplify the process of stripping whitespace consolidate it all to just
before we write the logs rather than earlier in the process.
Change-Id: I6ca957902a9ea4a5f0dfdddeda4bd398a81979d9
If we have to visually inspect the output of this test on every
run, we will fail, because we will certainly not visually inspect
the output of this test on every run. Let's at least try to
automate some of the validation.
Change-Id: Ib3b060c60d6037f664636b8854aa488573826a06
When iterating over complex objects, printing them out in the task
summary line is very noisy and hard to follow.
Change-Id: I4ae748f167ee03ba97a4bcbf2417dae0271e24a5
If an exception is thrown from ansible, we don't log it properly.
Add a playbook to the functional test of logging that doesn't mask
failures (it lets the tasks report as failed) So that we cover all four
possibilities for ansible module failure exception:
* failed task
* failed task in item
* failed task that reports as success
* failed task in item that reports as success
Change-Id: I9e355350f5ec34251f5030eaaa3f4bb7b4438a6e
Actually run a playbook against a second node with the plugins enabled,
then fetch the output so we can look at it.
Takes advantage of the fact that zuul_console will already be running on
the second node.
Change-Id: I75bcbc46ffbbb49f0689584fbdb1c62ac2e91737
Simon Westphahl