From 8266a4fb45621e08085c58537a531f33fc7eca74 Mon Sep 17 00:00:00 2001 From: Alan Jenkins Date: Wed, 10 Apr 2019 00:19:14 +0100 Subject: [PATCH 1/2] DNF: stderr is not ours to log to (and doing so breaks Ansible) stderr does not belong to etckeeper-dnf --------------------------------------- The Ansible dnf module uses the python dnf bindings. In contexts like these, stdout/stderr is owned by the host app (Ansible). dnf should not mess with stdout/stderr, unless the host app asks it to log there. Specifically, we were breaking the JSON output of the Ansible dnf module. This was only noticeable when the etckeeper message began with a "[" character. Ansible has a mechanism to try and skip header messages like login banners. However, "[" is a valid character to start a JSON document. https://unix.stackexchange.com/questions/511210/ansible-dnf-module-module-failure/ Solution -------- Instead, log any non-zero exit status through the dnf logger. For the pre-transaction etckeeper run, this message replaces an exception. So we now avoid logging a traceback, which did not appear to add anything useful. (In my testing, dnf was continued to install after the exception was logged). I have also added a warning message for the post-transaction etckeeper run. I switched from os.system() to subprocess.call(). The latter interface supports better error reporting. (When I tested os.system(), it returned an errno number which was indistinguishable from an exit code). etckeeper >/dev/null 2>&1 -------------------------- Any specific error messages from etckeeper are now discarded. Because unfortunately, python conventions about passing text strings have been somewhat unclear. It is an error to log strings if the encoding settings of a registered logger cannot handle them. Because a "bad" character causes the entire string to be discarded, and optionally an exception printed to stderr. In a previous proposal I showed code that should be correct in all expected cases. However, the length of comment required to define "all expected cases" was not very reassuring. That was on top of explaining that dnf has a workaround that will avoid raising exceptions when arbitrary unicode is logged to stdout. My proposal had to include that explanation, to show that we were not breaking a system package manager. It might sound strange to talk about error messages with characters we cannot encode. But I have one word for you: "filenames". (After the recent python PR #14008[1], logging.basicConfig() defaults to errors='backslashreplace'. Also, errors= can be manually specified when creating a lower-level logging "Handler". I think this will resolve the problem in the future. It means that when programs are written for this new version of python, it should be the responsibility of the log setup code to prevent UnicodeEncodeError.) [1] https://github.com/python/cpython/pull/14008 --- etckeeper-dnf/etckeeper.py | 27 ++++++++++++++++----------- 1 file changed, 16 insertions(+), 11 deletions(-) diff --git a/etckeeper-dnf/etckeeper.py b/etckeeper-dnf/etckeeper.py index e8a1a51..69edd88 100644 --- a/etckeeper-dnf/etckeeper.py +++ b/etckeeper-dnf/etckeeper.py @@ -9,7 +9,7 @@ from dnfpluginscore import logger -import os +import subprocess import dnf @@ -17,20 +17,25 @@ class Etckeeper(dnf.Plugin): name = 'etckeeper' - def _out(self, msg): - logger.debug('Etckeeper plugin: %s', msg) + def _run_command(self, command): + logger.debug('Etckeeper plugin: %s', command) + try: + with open("/dev/null", "wb") as devnull: + ret = subprocess.call(("etckeeper", command), + stdout=devnull, stderr=devnull, + close_fds=True) + if ret > 0: + logger.warning('"etckeeper %s" failed (exit code %d)' % (command, ret)) + if ret < 0: + logger.warning('"etckeeper %s" died (signal %d)' % (command, -ret)) + except OSError as err: + logger.warning('Failed to run "etckeeper %s": %s' % (command, err)) def resolved(self): - self._out('pre transaction commit') - command = '%s %s' % ('etckeeper', " pre-install") - ret = os.system(command) - if ret != 0: - raise dnf.exceptions.Error('etckeeper returned %d' % (ret >> 8)) + self._run_command("pre-install") def transaction(self): - self._out('post transaction commit') - command = '%s %s > /dev/null' % ('etckeeper', "post-install") - os.system(command) + self._run_command("post-install") if __name__ == "__main__": from distutils.core import setup -- 2.23.0 From 7cda9678b1e60c0495a2a522721b319843d5fae0 Mon Sep 17 00:00:00 2001 From: Alan Jenkins Date: Tue, 23 Apr 2019 20:15:01 +0100 Subject: [PATCH 2/2] Do not use dnfpluginscore.logger dnfpluginscore is not core support for dnf plugins, it is just a collection of "core plugins" for dnf. There is equally dnfpluginsextras and dnfpluginsextras.logger. A comment in dnf.logger comment says the logger name 'dnf.plugin' is "api". So we can safely rely on that name. Technically you can install etckeeper without the dnfpluginscore package (at least I managed to run into this for python2, on a Fedora 29 system which uses python3 for dnf by default). --- etckeeper-dnf/etckeeper.py | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/etckeeper-dnf/etckeeper.py b/etckeeper-dnf/etckeeper.py index 69edd88..d9dd2c3 100644 --- a/etckeeper-dnf/etckeeper.py +++ b/etckeeper-dnf/etckeeper.py @@ -7,11 +7,12 @@ # Distutils code below was copied from etckeeper-bzr distributed with v1.15 # -from dnfpluginscore import logger - +import logging import subprocess import dnf +logger = logging.getLogger('dnf.plugin') + class Etckeeper(dnf.Plugin): -- 2.23.0