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