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