ceph/src/ceph-volume/ceph_volume/process.py

   1 from fcntl import fcntl, F_GETFL, F_SETFL
   2 from os import O_NONBLOCK, read, path
   3 import subprocess
   4 from select import select
   5 from ceph_volume import terminal
   6 from ceph_volume.util import as_bytes
   7 from ceph_volume.util.system import which, run_host_cmd, host_rootfs
   8
   9 import logging
  10
  11 logger = logging.getLogger(__name__)
  12
  13
  14 def log_output(descriptor, message, terminal_logging, logfile_logging):
  15     """
  16     log output to both the logger and the terminal if terminal_logging is
  17     enabled
  18     """
  19     if not message:
  20         return
  21     message = message.strip()
  22     line = '%s %s' % (descriptor, message)
  23     if terminal_logging:
  24         getattr(terminal, descriptor)(message)
  25     if logfile_logging:
  26         logger.info(line)
  27
  28
  29 def log_descriptors(reads, process, terminal_logging):
  30     """
  31     Helper to send output to the terminal while polling the subprocess
  32     """
  33     # these fcntl are set to O_NONBLOCK for the filedescriptors coming from
  34     # subprocess so that the logging does not block. Without these a prompt in
  35     # a subprocess output would hang and nothing would get printed. Note how
  36     # these are just set when logging subprocess, not globally.
  37     stdout_flags = fcntl(process.stdout, F_GETFL) # get current p.stdout flags
  38     stderr_flags = fcntl(process.stderr, F_GETFL) # get current p.stderr flags
  39     fcntl(process.stdout, F_SETFL, stdout_flags | O_NONBLOCK)
  40     fcntl(process.stderr, F_SETFL, stderr_flags | O_NONBLOCK)
  41     descriptor_names = {
  42         process.stdout.fileno(): 'stdout',
  43         process.stderr.fileno(): 'stderr'
  44     }
  45     for descriptor in reads:
  46         descriptor_name = descriptor_names[descriptor]
  47         try:
  48             message = read(descriptor, 1024)
  49             if not isinstance(message, str):
  50                 message = message.decode('utf-8')
  51             log_output(descriptor_name, message, terminal_logging, True)
  52         except (IOError, OSError):
  53             # nothing else to log
  54             pass
  55
  56
  57 def obfuscate(command_, on=None):
  58     """
  59     Certain commands that are useful to log might contain information that
  60     should be replaced by '*' like when creating OSDs and the keyrings are
  61     being passed, which should not be logged.
  62
  63     :param on: A string (will match a flag) or an integer (will match an index)
  64
  65     If matching on a flag (when ``on`` is a string) it will obfuscate on the
  66     value for that flag. That is a command like ['ls', '-l', '/'] that calls
  67     `obfuscate(command, on='-l')` will obfustace '/' which is the value for
  68     `-l`.
  69
  70     The reason for `on` to allow either a string or an integer, altering
  71     behavior for both is because it is easier for ``run`` and ``call`` to just
  72     pop a value to obfuscate (vs. allowing an index or a flag)
  73     """
  74     command = command_[:]
  75     msg = "Running command: %s" % ' '.join(command)
  76     if on in [None, False]:
  77         return msg
  78
  79     if isinstance(on, int):
  80         index = on
  81
  82     else:
  83         try:
  84             index = command.index(on) + 1
  85         except ValueError:
  86             # if the flag just doesn't exist then it doesn't matter just return
  87             # the base msg
  88             return msg
  89
  90     try:
  91         command[index] = '*' * len(command[index])
  92     except IndexError: # the index was completely out of range
  93         return msg
  94
  95     return "Running command: %s" % ' '.join(command)
  96
  97
  98 def run(command, run_on_host=False, **kw):
  99     """
 100     A real-time-logging implementation of a remote subprocess.Popen call where
 101     a command is just executed on the remote end and no other handling is done.
 102
 103     :param command: The command to pass in to the remote subprocess.Popen as a list
 104     :param stop_on_error: If a nonzero exit status is return, it raises a ``RuntimeError``
 105     :param fail_msg: If a nonzero exit status is returned this message will be included in the log
 106     """
 107     executable = which(command.pop(0), run_on_host)
 108     command.insert(0, executable)
 109     if run_on_host and path.isdir(host_rootfs):
 110         command = run_host_cmd + command
 111     stop_on_error = kw.pop('stop_on_error', True)
 112     command_msg = obfuscate(command, kw.pop('obfuscate', None))
 113     fail_msg = kw.pop('fail_msg', None)
 114     logger.info(command_msg)
 115     terminal.write(command_msg)
 116     terminal_logging = kw.pop('terminal_logging', True)
 117
 118     process = subprocess.Popen(
 119         command,
 120         stdout=subprocess.PIPE,
 121         stderr=subprocess.PIPE,
 122         close_fds=True,
 123         **kw
 124     )
 125
 126     while True:
 127         reads, _, _ = select(
 128             [process.stdout.fileno(), process.stderr.fileno()],
 129             [], []
 130         )
 131         log_descriptors(reads, process, terminal_logging)
 132
 133         if process.poll() is not None:
 134             # ensure we do not have anything pending in stdout or stderr
 135             log_descriptors(reads, process, terminal_logging)
 136
 137             break
 138
 139     returncode = process.wait()
 140     if returncode != 0:
 141         msg = "command returned non-zero exit status: %s" % returncode
 142         if fail_msg:
 143             logger.warning(fail_msg)
 144             if terminal_logging:
 145                 terminal.warning(fail_msg)
 146         if stop_on_error:
 147             raise RuntimeError(msg)
 148         else:
 149             if terminal_logging:
 150                 terminal.warning(msg)
 151             logger.warning(msg)
 152
 153
 154 def call(command, run_on_host=False, **kw):
 155     """
 156     Similar to ``subprocess.Popen`` with the following changes:
 157
 158     * returns stdout, stderr, and exit code (vs. just the exit code)
 159     * logs the full contents of stderr and stdout (separately) to the file log
 160
 161     By default, no terminal output is given, not even the command that is going
 162     to run.
 163
 164     Useful when system calls are needed to act on output, and that same output
 165     shouldn't get displayed on the terminal.
 166
 167     Optionally, the command can be displayed on the terminal and the log file,
 168     and log file output can be turned off. This is useful to prevent sensitive
 169     output going to stderr/stdout and being captured on a log file.
 170
 171     :param terminal_verbose: Log command output to terminal, defaults to False, and
 172                              it is forcefully set to True if a return code is non-zero
 173     :param logfile_verbose: Log stderr/stdout output to log file. Defaults to True
 174     :param verbose_on_failure: On a non-zero exit status, it will forcefully set logging ON for
 175                                the terminal. Defaults to True
 176     """
 177     executable = which(command.pop(0), run_on_host)
 178     command.insert(0, executable)
 179     if run_on_host and path.isdir(host_rootfs):
 180         command = run_host_cmd + command
 181     terminal_verbose = kw.pop('terminal_verbose', False)
 182     logfile_verbose = kw.pop('logfile_verbose', True)
 183     verbose_on_failure = kw.pop('verbose_on_failure', True)
 184     show_command = kw.pop('show_command', False)
 185     command_msg = "Running command: %s" % ' '.join(command)
 186     stdin = kw.pop('stdin', None)
 187     logger.info(command_msg)
 188     if show_command:
 189         terminal.write(command_msg)
 190
 191     process = subprocess.Popen(
 192         command,
 193         stdout=subprocess.PIPE,
 194         stderr=subprocess.PIPE,
 195         stdin=subprocess.PIPE,
 196         close_fds=True,
 197         **kw
 198     )
 199
 200     if stdin:
 201         stdout_stream, stderr_stream = process.communicate(as_bytes(stdin))
 202     else:
 203         stdout_stream = process.stdout.read()
 204         stderr_stream = process.stderr.read()
 205     returncode = process.wait()
 206     if not isinstance(stdout_stream, str):
 207         stdout_stream = stdout_stream.decode('utf-8')
 208     if not isinstance(stderr_stream, str):
 209         stderr_stream = stderr_stream.decode('utf-8')
 210     stdout = stdout_stream.splitlines()
 211     stderr = stderr_stream.splitlines()
 212
 213     if returncode != 0:
 214         # set to true so that we can log the stderr/stdout that callers would
 215         # do anyway as long as verbose_on_failure is set (defaults to True)
 216         if verbose_on_failure:
 217             terminal_verbose = True
 218         # logfiles aren't disruptive visually, unlike the terminal, so this
 219         # should always be on when there is a failure
 220         logfile_verbose = True
 221
 222     # the following can get a messed up order in the log if the system call
 223     # returns output with both stderr and stdout intermingled. This separates
 224     # that.
 225     for line in stdout:
 226         log_output('stdout', line, terminal_verbose, logfile_verbose)
 227     for line in stderr:
 228         log_output('stderr', line, terminal_verbose, logfile_verbose)
 229     return stdout, stderr, returncode