| 1 | import os |
| 2 | import sys |
| 3 | import shlex |
| 4 | import subprocess |
| 5 | import uuid |
| 6 | import logging |
| 7 | import shutil |
| 8 | import contextlib |
| 9 | import pprint |
| 10 | |
| 11 | from tempfile import TemporaryDirectory |
| 12 | |
| 13 | import lttng_ivc.settings as Settings |
| 14 | _logger = logging.getLogger("Runtime") |
| 15 | |
| 16 | |
| 17 | @contextlib.contextmanager |
| 18 | def get_runtime(runtime_dir): |
| 19 | runtime = Runtime(runtime_dir) |
| 20 | try: |
| 21 | yield runtime |
| 22 | finally: |
| 23 | runtime.close() |
| 24 | |
| 25 | |
| 26 | class Runtime(object): |
| 27 | def __init__(self, runtime_dir): |
| 28 | """ |
| 29 | A dictionary of popen object eg. lttng-sessiond, relayd, |
| 30 | anything really. Key is a uuid. |
| 31 | """ |
| 32 | self.__subprocess = {} |
| 33 | self.__stdout_stderr = {} |
| 34 | self.__projects = [] |
| 35 | |
| 36 | self.__runtime_log = os.path.join(runtime_dir, "log") |
| 37 | self.__runtime_log_sub = os.path.join(self.__runtime_log, "subprocess") |
| 38 | |
| 39 | """ |
| 40 | Path of the copy of lttng_home folder after Runtime.close() is issued. This is |
| 41 | to be used for post runtime analysis and mostly debugging on error. |
| 42 | """ |
| 43 | self.__post_runtime_lttng_home_path = os.path.join(runtime_dir, |
| 44 | "lttng_home") |
| 45 | |
| 46 | self._runtime_log_aggregation = os.path.join(self.__runtime_log, "runtime.log") |
| 47 | |
| 48 | self._run_command_count = 0 |
| 49 | self._is_test_modules_loaded = False |
| 50 | |
| 51 | self.special_env_variables = {"LTTNG_UST_DEBUG": "1", |
| 52 | "LTTNG_APP_SOCKET_TIMEOUT": "-1", |
| 53 | #"LTTNG_UST_REGISTER_TIMEOUT": "-1", |
| 54 | "LTTNG_NETWORK_SOCKET_TIMEOUT": "-1"} |
| 55 | |
| 56 | # Keep a reference on the object to keep it alive. It will close/clean on |
| 57 | # exit. |
| 58 | self.__lttng_home_dir = TemporaryDirectory(prefix=Settings.tmp_object_prefix) |
| 59 | self.lttng_home = self.__lttng_home_dir.name |
| 60 | |
| 61 | if len(self.lttng_home) > 88: |
| 62 | raise Exception("TemporaryDirectory for lttng_home is to long. Use a short TMPDIR") |
| 63 | |
| 64 | os.makedirs(self.__runtime_log) |
| 65 | os.makedirs(self.__runtime_log_sub) |
| 66 | |
| 67 | def add_project(self, project): |
| 68 | self.__projects.append(project) |
| 69 | |
| 70 | def remove_project(self, project): |
| 71 | self.__projects.remove(project) |
| 72 | |
| 73 | def subprocess_signal(self, subprocess_uuid, signal): |
| 74 | self.__subproces[subprocess_uuid].send_signal(signal) |
| 75 | |
| 76 | def subprocess_terminate(self, subprocess_uuid, timeout=60, check_return=True): |
| 77 | process = self.__subprocess[subprocess_uuid] |
| 78 | process.terminate() |
| 79 | try: |
| 80 | process.wait(timeout) |
| 81 | except subprocess.TimeoutExpired: |
| 82 | # Force kill |
| 83 | return self.subprocess_kill(subprocess_uuid) |
| 84 | stdout, stderr = self.__stdout_stderr[subprocess_uuid] |
| 85 | stdout.close() |
| 86 | stderr.close() |
| 87 | if check_return: |
| 88 | if process.returncode != 0: |
| 89 | raise subprocess.CalledProcessError(process.returncode, process.args) |
| 90 | return process |
| 91 | |
| 92 | def subprocess_kill(self, subprocess_uuid): |
| 93 | process = self.__subprocess[subprocess_uuid] |
| 94 | process.kill() |
| 95 | process.wait() |
| 96 | stdout, stderr = self.__stdout_stderr[subprocess_uuid] |
| 97 | stdout.close() |
| 98 | stderr.close() |
| 99 | return process |
| 100 | |
| 101 | def subprocess_wait(self, subprocess_uuid, check_return=True): |
| 102 | process = self.__subprocess[subprocess_uuid] |
| 103 | process.wait() |
| 104 | stdout, stderr = self.__stdout_stderr[subprocess_uuid] |
| 105 | stdout.close() |
| 106 | stderr.close() |
| 107 | if check_return: |
| 108 | if process.returncode != 0: |
| 109 | raise subprocess.CalledProcessError(process.returncode, process.args) |
| 110 | return process |
| 111 | |
| 112 | def get_subprocess_stdout_path(self, subprocess_uuid): |
| 113 | stdout, stderr = self.__stdout_stderr[subprocess_uuid] |
| 114 | return stdout.name |
| 115 | |
| 116 | def get_subprocess_stderr_path(self, subprocess_uuid): |
| 117 | stdout, stderr = self.__stdout_stderr[subprocess_uuid] |
| 118 | return stderr.name |
| 119 | |
| 120 | def spawn_subprocess(self, command_line, cwd=None): |
| 121 | args = shlex.split(command_line) |
| 122 | env = self.get_env() |
| 123 | |
| 124 | if not os.path.isdir(self.lttng_home): |
| 125 | raise Exception("lttng home does not exist") |
| 126 | |
| 127 | tmp_id = uuid.uuid1() |
| 128 | out_path = os.path.join(self.__runtime_log_sub, str(tmp_id) + ".out") |
| 129 | err_path = os.path.join(self.__runtime_log_sub, str(tmp_id) + ".err") |
| 130 | |
| 131 | stdout = open(out_path, 'w') |
| 132 | stderr = open(err_path, 'w') |
| 133 | |
| 134 | env_path = os.path.join(self.__runtime_log_sub, str(tmp_id) + ".env") |
| 135 | with open(env_path, 'w') as env_out: |
| 136 | pprint.pprint(env, stream=env_out) |
| 137 | |
| 138 | p = subprocess.Popen(args, stdout=stdout, stderr=stderr, env=env, cwd=cwd) |
| 139 | self.__subprocess[tmp_id] = p |
| 140 | self.__stdout_stderr[tmp_id] = (stdout, stderr) |
| 141 | _logger.debug("Spawned sub pid: {} args: {} stdout: {} stderr{}".format(p.pid, p.args, out_path, err_path)) |
| 142 | return tmp_id |
| 143 | |
| 144 | def run(self, command_line, cwd=None, check_return=True, ld_preload="", classpath=""): |
| 145 | """ |
| 146 | Run the command and return a tuple of a (CompletedProcess, stdout_path, |
| 147 | stderr_path). The subprocess is already executed and returned. The |
| 148 | callecaller is responsible for checking for errors. |
| 149 | """ |
| 150 | args = shlex.split(command_line) |
| 151 | env = self.get_env() |
| 152 | |
| 153 | if ld_preload: |
| 154 | env['LD_PRELOAD'] = ld_preload |
| 155 | if classpath: |
| 156 | env['CLASSPATH'] = classpath |
| 157 | |
| 158 | |
| 159 | tmp_id = self._run_command_count |
| 160 | self._run_command_count += 1 |
| 161 | |
| 162 | cmd_map = os.path.join(self.__runtime_log, "cmd.map") |
| 163 | with open(cmd_map, 'a') as out: |
| 164 | out.write("{}: {}\n".format(tmp_id, args)) |
| 165 | |
| 166 | out_path = os.path.join(self.__runtime_log, str(tmp_id) + ".out") |
| 167 | err_path = os.path.join(self.__runtime_log, str(tmp_id) + ".err") |
| 168 | stdout = open(out_path, "w") |
| 169 | stderr = open(err_path, "w") |
| 170 | |
| 171 | env_path = os.path.join(self.__runtime_log, str(tmp_id) + ".env") |
| 172 | with open(env_path, 'w') as env_out: |
| 173 | for key, value in env.items(): |
| 174 | env_out.write('{}={}\n'.format(key, value)) |
| 175 | |
| 176 | cp = subprocess.run(args, stdout=stdout, stderr=stderr, env=env, cwd=cwd) |
| 177 | _logger.debug("Command #{} args: {} stdout: {} stderr{}".format(tmp_id, cp.args, out_path, err_path)) |
| 178 | |
| 179 | # Add to the global log file. This can help a little. Leave the other |
| 180 | # file available for per-run analysis |
| 181 | with open(self._runtime_log_aggregation, "a") as log: |
| 182 | with open(out_path, "r") as out: |
| 183 | log.write("Output for command #{} {}\n".format(tmp_id, command_line)) |
| 184 | log.write("Start >>>>>>>>>>>>>>>>\n") |
| 185 | log.write(out.read()) |
| 186 | log.write("End <<<<<<<<<<<<<<<<\n") |
| 187 | with open(err_path, "r") as out: |
| 188 | log.write("Error for command #{} {}\n".format(tmp_id, command_line)) |
| 189 | log.write("Start >>>>>>>>>>>>>>>>\n") |
| 190 | log.write(out.read()) |
| 191 | log.write("End <<<<<<<<<<<<<<<<\n") |
| 192 | |
| 193 | if check_return: |
| 194 | cp.check_returncode() |
| 195 | |
| 196 | return (cp, out_path, err_path) |
| 197 | |
| 198 | def get_cppflags(self): |
| 199 | cppflags = [] |
| 200 | for project in self.__projects: |
| 201 | cppflags.append(project.get_cppflags()) |
| 202 | return " ".join(cppflags) |
| 203 | |
| 204 | def get_ldflags(self): |
| 205 | ldflags = [] |
| 206 | for project in self.__projects: |
| 207 | ldflags.append(project.get_ldflags()) |
| 208 | return " ".join(ldflags) |
| 209 | |
| 210 | def get_ld_library_path(self): |
| 211 | library_path = [] |
| 212 | for project in self.__projects: |
| 213 | library_path.append(project.get_ld_library_path()) |
| 214 | return ":".join(library_path) |
| 215 | |
| 216 | def get_bin_path(self): |
| 217 | path = [] |
| 218 | for project in self.__projects: |
| 219 | path.append(project.get_bin_path()) |
| 220 | return ":".join(path) |
| 221 | |
| 222 | def get_env(self): |
| 223 | env = os.environ.copy() |
| 224 | |
| 225 | env["LTTNG_HOME"] = self.lttng_home |
| 226 | |
| 227 | env_fetch = {"CPPFLAGS": (self.get_cppflags(), " "), |
| 228 | "LDFLAGS": (self.get_ldflags(), " "), |
| 229 | "LD_LIBRARY_PATH": (self.get_ld_library_path(), ":"), |
| 230 | "PATH": (self.get_bin_path(), ":"), |
| 231 | } |
| 232 | for key, (value, delimiter) in env_fetch.items(): |
| 233 | tmp_var = "" |
| 234 | if key in env: |
| 235 | tmp_var = env[key] |
| 236 | env[key] = delimiter.join([value, tmp_var]) |
| 237 | |
| 238 | for var, value in self.special_env_variables.items(): |
| 239 | if var in env: |
| 240 | # Raise for now since no special cases is known |
| 241 | _logger.warning("% Special var % is already defined", |
| 242 | self.label, var) |
| 243 | raise Exception("Multiple definition of a special environment variable") |
| 244 | else: |
| 245 | env[var] = value |
| 246 | |
| 247 | for project in self.__projects: |
| 248 | for var, value in project.special_env_variables.items(): |
| 249 | if var in env: |
| 250 | # Raise for now since no special cases is known |
| 251 | _logger.warning("% Special var % is already defined", |
| 252 | self.label, var) |
| 253 | raise Exception("Multiple definition of a special environment variable") |
| 254 | else: |
| 255 | env[var] = value |
| 256 | return env |
| 257 | |
| 258 | def load_test_module(self): |
| 259 | # Base directory is provided by env |
| 260 | self.run("modprobe lttng-test") |
| 261 | self._is_test_modules_loaded = True |
| 262 | |
| 263 | def unload_test_module(self, check_return=True): |
| 264 | # Base directory is provided by env |
| 265 | if self._is_test_modules_loaded: |
| 266 | self.run("modprobe -r lttng-test", check_return=check_return) |
| 267 | |
| 268 | def close(self): |
| 269 | for key, subp in self.__subprocess.items(): |
| 270 | subp.terminate() |
| 271 | for key, subp in self.__subprocess.items(): |
| 272 | # TODO move timeout to settings |
| 273 | subp.wait(timeout=60) |
| 274 | for key, (stdout, stderr) in self.__stdout_stderr.items(): |
| 275 | stdout.close() |
| 276 | stderr.close() |
| 277 | |
| 278 | # Always try to remove test module but do not perform check on return |
| 279 | # value. |
| 280 | self.unload_test_module(False) |
| 281 | |
| 282 | # Copy the lttng_home used at runtime using hardlink to prevent useless |
| 283 | # data duplication |
| 284 | shutil.copytree(self.lttng_home, self.__post_runtime_lttng_home_path, copy_function=os.link) |