Instead of messing with yum output just write json to a file

Instead of messing with the yum output, which makes it hard
to debug when failures occur just write the json output to
a provided filename and load this when running yyoom instead.

At the same time write the yyoom full log to a given log dir
that contains each yyoom invocations output (now with more
details!).

Change-Id: I550265bb890b4f785ddbcaa8abff03e2fe5e8983
This commit is contained in:
Joshua Harlow 2014-05-28 16:49:51 -07:00
parent 0795ab0d20
commit 49b8be99ee
4 changed files with 86 additions and 76 deletions

View File

@ -14,7 +14,8 @@
# License for the specific language governing permissions and limitations
# under the License.
import sys
import tempfile
import time
from anvil import exceptions as excp
from anvil import log as logging
@ -24,38 +25,71 @@ from anvil import utils
LOG = logging.getLogger(__name__)
def _generate_log_filename(arglist):
pieces = ['yyoom-']
for a in arglist:
a = a.strip()
if not a or a.startswith("-") or sh.exists(a):
break
else:
pieces.append(a)
pieces.append("_")
pieces.append(int(time.time()))
pieces.append("_")
pieces.append(utils.get_random_string(4))
pieces.append('.log')
return "".join([str(p) for p in pieces])
class Helper(object):
def __init__(self, log_dir, repos):
# Executables we require to operate
self.yyoom_executable = sh.which("yyoom", ["tools/"])
# Executable logs will go into this file
self._log_file = sh.joinpths(log_dir, "yyoom.log")
# Preferred repositories names
self._repos = repos
# Caches of installed and available packages
self._installed = None
self._available = None
self._logs_dir = log_dir
def _yyoom(self, arglist):
cmdline = [self.yyoom_executable, '--quiet',
'--log-file', self._log_file]
cmdline.extend(arglist)
(stdout, _) = sh.execute(cmdline, stderr_fh=sys.stderr)
return utils.parse_json(stdout)
def _yyoom(self, arglist, on_completed=None):
if not on_completed:
on_completed = lambda data, errored: None
if not sh.isdir(self._logs_dir):
sh.mkdirslist(self._logs_dir)
with tempfile.NamedTemporaryFile(suffix=".json") as fh:
cmdline = [
self.yyoom_executable,
"--output-file", fh.name,
"--verbose",
]
cmdline.extend(arglist)
log_filename = sh.joinpths(self._logs_dir,
_generate_log_filename(arglist))
LOG.debug("Running yyoom: log output will be placed in %s",
log_filename)
try:
sh.execute_save_output(cmdline, log_filename)
except excp.ProcessExecutionError:
with excp.reraise():
try:
fh.seek(0)
data = utils.parse_json(fh.read())
except Exception:
LOG.exception("Failed to parse YYOOM output")
else:
on_completed(data, True)
else:
fh.seek(0)
data = utils.parse_json(fh.read())
on_completed(data, False)
return data
def _traced_yyoom(self, arglist, tracewriter):
try:
data = self._yyoom(arglist)
except excp.ProcessExecutionError:
with excp.reraise() as ex:
try:
data = utils.parse_json(ex.stdout)
except Exception:
LOG.exception("Failed to parse YYOOM output")
else:
self._handle_transaction_data(tracewriter, data)
self._handle_transaction_data(tracewriter, data)
def on_completed(data, errored):
self._handle_transaction_data(tracewriter, data)
return self._yyoom(arglist, on_completed=on_completed)
@staticmethod
def _handle_transaction_data(tracewriter, data):
@ -99,8 +133,7 @@ class Helper(object):
return list(self._installed)
def builddep(self, srpm_path, tracewriter=None):
self._traced_yyoom(['builddep', srpm_path],
tracewriter)
self._traced_yyoom(['builddep', srpm_path], tracewriter)
def _reset(self):
# reset the caches:

View File

@ -15,14 +15,13 @@
# License for the specific language governing permissions and limitations
# under the License.
import binascii
import getpass
import os
from keyring.backend import CryptedFileKeyring
from keyring.backend import UncryptedFileKeyring
from anvil import log as logging
from anvil import utils
LOG = logging.getLogger(__name__)
RAND_PW_LEN = 20
@ -95,9 +94,7 @@ class RandomPassword(object):
def generate_random(self, length):
"""Returns a randomly generated password of the specified length."""
LOG.debug("Generating a pseudo-random secret of %d characters", length)
if length <= 0:
return ''
return binascii.hexlify(os.urandom((length + 1) / 2))[:length]
return utils.get_random_string(length)
def get_password(self, option, length):
return self.generate_random(int(length))

View File

@ -17,6 +17,7 @@
# License for the specific language governing permissions and limitations
# under the License.
import binascii
import contextlib
import glob
import json
@ -141,6 +142,13 @@ def expand_template_deep(root, params):
return root
def get_random_string(length):
"""Get a random hex string of the specified length."""
if length <= 0:
return ''
return binascii.hexlify(os.urandom((length + 1) / 2))[:length]
def parse_json(text):
"""Load JSON from string

View File

@ -41,7 +41,6 @@ from contextlib import contextmanager
LOG = logging.getLogger('yyoom')
OUTPUT = None
ACTION_TYPE_MAP = {
yum.constants.TS_INSTALL: 'install',
yum.constants.TS_TRUEINSTALL: 'install',
@ -54,6 +53,14 @@ ACTION_TYPE_MAP = {
}
def _write_output(data, where):
"""Dump given object as pretty json"""
where.write(json.dumps(data, indent=4,
separators=(',', ': '),
sort_keys=True) + '\n')
where.flush()
def _extended_yum_raises(method):
"""Decorator to extend error messages when manipulating packages with yum.
"""
@ -102,34 +109,6 @@ class _YyoomBase(yum.YumBase):
return super(_YyoomBase, self).remove(po, **kwargs)
def _setup_output():
"""Do some nasty manipulations with fds
Yum internals may sometimes write to stdout, just out of a sudden.
To prevent this output form interfering with our JSON, we save
current stdout to other fd via os.dup, and replace fd 1 with
/dev/null opened for writing.
"""
global OUTPUT
# save current stdout for later use
OUTPUT = os.fdopen(os.dup(sys.stdout.fileno()), 'wb')
# close the stream
sys.stdout.close()
# open /dev/null -- all writes to stdout from now on will go there
devnull_fd = os.open(os.devnull, os.O_WRONLY)
if devnull_fd != 1:
os.dup2(devnull_fd, 1)
os.close(devnull_fd)
sys.stdout = os.fdopen(1, 'w')
def _write_output(data):
"""Dump given object as pretty json"""
OUTPUT.write(json.dumps(data, indent=4,
separators=(',', ': '),
sort_keys=True) + '\n')
def _action_type_from_code(action):
"""Return value according to action code in dictionary mapping Yum states.
@ -185,10 +164,11 @@ class _RPMCallback(yum.rpmtrans.RPMBaseCallback):
class _OutputtingRPMCallback(_RPMCallback):
def __init__(self, skip_missing=False):
def __init__(self, options):
_RPMCallback.__init__(self)
self._skip_missing = skip_missing
self._skip_missing = options.skip_missing
self._missing = []
self._options = options
def yyoom_post_transaction(self, base, _code):
output = []
@ -198,12 +178,12 @@ class _OutputtingRPMCallback(_RPMCallback):
action_code=txmbr.output_state,
action_type=action_type)
output.append(info)
_write_output(output + self._missing)
with open(self._options.output_file, 'ab') as fh:
_write_output(output + self._missing, fh)
def yyoom_on_missing_package(self, pkg_req):
if not self._skip_missing:
raise yum.Errors.InstallError("The '%s' package not found." % pkg_req)
req = pkg_resources.Requirement.parse(pkg_req)
self._missing.append(_package_info(req.unsafe_name,
action_type="missing",
@ -254,7 +234,7 @@ def _run(yum_base, options):
log_list(options.erase, title='Erasing packages:')
log_list(options.install, title='Installing packages:')
with _transaction(yum_base,
_OutputtingRPMCallback(options.skip_missing)) as cb:
_OutputtingRPMCallback(options)) as cb:
yum_map = build_yum_map(yum_base)
# erase packages
for pkg_name in options.erase or ():
@ -288,7 +268,6 @@ def _list(yum_base, options):
"%s available for reinstall, %s extras",
pkgnarrow, len(lists.installed), len(lists.available),
len(lists.reinstall_available), len(lists.extras))
result = []
if 'installed' in options.what:
result.extend(_package_info(pkg, status='installed')
@ -301,7 +280,8 @@ def _list(yum_base, options):
if 'extras' in options.what:
result.extend(_package_info(pkg, status='installed')
for pkg in lists.extras)
_write_output(result)
with open(options.output_file, 'ab') as fh:
_write_output(result, fh)
def _cleanall(yum_base, options):
@ -325,7 +305,7 @@ def _builddep(yum_base, options):
"""
LOG.info("Installing build dependencies for package %s", options.srpm)
srpm = yum.packages.YumLocalPackage(yum_base.ts, options.srpm)
with _transaction(yum_base, _OutputtingRPMCallback()):
with _transaction(yum_base, _OutputtingRPMCallback(options)):
for req in srpm.requiresList():
LOG.debug('Processing dependency: %s', req)
if not (
@ -341,8 +321,9 @@ def _parse_arguments(args):
parser = argparse.ArgumentParser(prog=args[0])
parser.add_argument('--verbose', '-v', action='store_true',
help='verbose operation')
parser.add_argument('--log-file', '-l')
parser.add_argument('--output-file', '-o', required=True)
parser.add_argument('--quiet', '-q', action='store_true')
# TODO(imelnikov): --format
subparsers = parser.add_subparsers(title='subcommands')
@ -384,9 +365,8 @@ def _parse_arguments(args):
return parser.parse_args(args[1:] or ['--help'])
def _setup_logging(verbose=True, logfile=None, quiet=False):
def _setup_logging(verbose=True, quiet=False):
"""Initialize logging"""
# setup logging -- put messages to stderr
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(logging.Formatter('YYOOM %(levelname)s: %(message)s'))
if quiet:
@ -399,13 +379,6 @@ def _setup_logging(verbose=True, logfile=None, quiet=False):
root_logger = logging.getLogger()
root_logger.addHandler(handler)
root_logger.setLevel(logging.DEBUG)
# Setup logfile if we have one
if logfile:
file_handler = logging.FileHandler(logfile)
file_handler.setFormatter(
logging.Formatter('%(asctime)s %(levelname)s: %(message)s'))
file_handler.setLevel(logging.DEBUG)
root_logger.addHandler(file_handler)
def _run_yum_api(name, func, ok_codes=(0,), *args, **kwargs):
@ -457,8 +430,7 @@ def _transaction(base, callback):
def main(args):
options = _parse_arguments(args)
_setup_output()
_setup_logging(options.verbose, options.log_file, options.quiet)
_setup_logging(options.verbose, options.quiet)
LOG.debug('Running YOOM %s', options.operation)
LOG.debug('Command line: %s', subprocess.list2cmdline(args))
try: