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

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