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