1# Microsoft Azure Linux Agent 2# 3# Copyright 2020 Microsoft Corporation 4# 5# Licensed under the Apache License, Version 2.0 (the "License"); 6# you may not use this file except in compliance with the License. 7# You may obtain a copy of the License at 8# 9# http://www.apache.org/licenses/LICENSE-2.0 10# 11# Unless required by applicable law or agreed to in writing, software 12# distributed under the License is distributed on an "AS IS" BASIS, 13# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 14# See the License for the specific language governing permissions and 15# limitations under the License. 16# 17# Requires Python 2.6+ and Openssl 1.0+ 18# 19 20import glob 21import logging 22import os 23import subprocess 24import time 25import zipfile 26from datetime import datetime 27from heapq import heappush, heappop 28 29from azurelinuxagent.common.conf import get_lib_dir, get_ext_log_dir, get_agent_log_file 30from azurelinuxagent.common.future import ustr 31from azurelinuxagent.common.logcollector_manifests import MANIFEST_NORMAL, MANIFEST_FULL 32 33# Please note: be careful when adding agent dependencies in this module. 34# This module uses its own logger and logs to its own file, not to the agent log. 35 36_EXTENSION_LOG_DIR = get_ext_log_dir() 37_AGENT_LIB_DIR = get_lib_dir() 38_AGENT_LOG = get_agent_log_file() 39 40_LOG_COLLECTOR_DIR = os.path.join(_AGENT_LIB_DIR, "logcollector") 41_TRUNCATED_FILES_DIR = os.path.join(_LOG_COLLECTOR_DIR, "truncated") 42 43OUTPUT_RESULTS_FILE_PATH = os.path.join(_LOG_COLLECTOR_DIR, "results.txt") 44COMPRESSED_ARCHIVE_PATH = os.path.join(_LOG_COLLECTOR_DIR, "logs.zip") 45 46_MUST_COLLECT_FILES = [ 47 _AGENT_LOG, 48 os.path.join(_AGENT_LIB_DIR, "GoalState.*.xml"), 49 os.path.join(_AGENT_LIB_DIR, "ExtensionsConfig.*.xml"), 50 os.path.join(_AGENT_LIB_DIR, "HostingEnvironmentConfig.*.xml"), 51 os.path.join(_AGENT_LIB_DIR, "SharedConfig.*.xml"), 52 os.path.join(_AGENT_LIB_DIR, "*manifest.xml"), 53 os.path.join(_AGENT_LIB_DIR, "waagent_status.json"), 54 os.path.join(_AGENT_LIB_DIR, "history", "*.zip"), 55 os.path.join(_EXTENSION_LOG_DIR, "*", "*"), 56 os.path.join(_EXTENSION_LOG_DIR, "*", "*", "*"), 57 "{0}.*".format(_AGENT_LOG) # any additional waagent.log files (e.g., waagent.log.1.gz) 58] 59 60_FILE_SIZE_LIMIT = 30 * 1024 * 1024 # 30 MB 61_UNCOMPRESSED_ARCHIVE_SIZE_LIMIT = 150 * 1024 * 1024 # 150 MB 62 63_LOGGER = logging.getLogger(__name__) 64 65 66class LogCollector(object): 67 68 _TRUNCATED_FILE_PREFIX = "truncated_" 69 70 def __init__(self, is_full_mode=False): 71 self._is_full_mode = is_full_mode 72 self._manifest = MANIFEST_FULL if is_full_mode else MANIFEST_NORMAL 73 self._must_collect_files = self._expand_must_collect_files() 74 self._create_base_dirs() 75 self._set_logger() 76 77 @staticmethod 78 def _mkdir(dirname): 79 if not os.path.isdir(dirname): 80 os.makedirs(dirname) 81 82 @staticmethod 83 def _reset_file(filepath): 84 with open(filepath, "wb") as out_file: 85 out_file.write("".encode("utf-8")) 86 87 @staticmethod 88 def _create_base_dirs(): 89 LogCollector._mkdir(_LOG_COLLECTOR_DIR) 90 LogCollector._mkdir(_TRUNCATED_FILES_DIR) 91 92 @staticmethod 93 def _set_logger(): 94 _f_handler = logging.FileHandler(OUTPUT_RESULTS_FILE_PATH, encoding="utf-8") 95 _f_format = logging.Formatter(fmt='%(asctime)s %(levelname)s %(message)s', 96 datefmt=u'%Y-%m-%dT%H:%M:%SZ') 97 _f_format.converter = time.gmtime 98 _f_handler.setFormatter(_f_format) 99 _LOGGER.addHandler(_f_handler) 100 _LOGGER.setLevel(logging.INFO) 101 102 @staticmethod 103 def _run_shell_command(command, stdout=subprocess.PIPE, log_output=False): 104 """ 105 Runs a shell command in a subprocess, logs any errors to the log file, enables changing the stdout stream, 106 and logs the output of the command to the log file if indicated by the `log_output` parameter. 107 :param command: Shell command to run 108 :param stdout: Where to write the output of the command 109 :param log_output: If true, log the command output to the log file 110 """ 111 def format_command(cmd): 112 return " ".join(cmd) if isinstance(cmd, list) else command 113 114 def _encode_command_output(output): 115 return ustr(output, encoding="utf-8", errors="backslashreplace") 116 117 try: 118 process = subprocess.Popen(command, stdout=stdout, stderr=subprocess.PIPE, shell=False) 119 stdout, stderr = process.communicate() 120 return_code = process.returncode 121 except Exception as e: 122 error_msg = u"Command [{0}] raised unexpected exception: [{1}]".format(format_command(command), ustr(e)) 123 _LOGGER.error(error_msg) 124 return 125 126 if return_code != 0: 127 encoded_stdout = _encode_command_output(stdout) 128 encoded_stderr = _encode_command_output(stderr) 129 error_msg = "Command: [{0}], return code: [{1}], stdout: [{2}] stderr: [{3}]".format(format_command(command), 130 return_code, 131 encoded_stdout, 132 encoded_stderr) 133 _LOGGER.error(error_msg) 134 return 135 136 if log_output: 137 msg = "Output of command [{0}]:\n{1}".format(format_command(command), _encode_command_output(stdout)) 138 _LOGGER.info(msg) 139 140 @staticmethod 141 def _expand_must_collect_files(): 142 # Match the regexes from the MUST_COLLECT_FILES list to existing file paths on disk. 143 manifest = [] 144 for path in _MUST_COLLECT_FILES: 145 manifest.extend(sorted(glob.glob(path))) 146 147 return manifest 148 149 def _read_manifest(self): 150 return self._manifest.splitlines() 151 152 @staticmethod 153 def _process_ll_command(folder): 154 LogCollector._run_shell_command(["ls", "-alF", folder], log_output=True) 155 156 @staticmethod 157 def _process_echo_command(message): 158 _LOGGER.info(message) 159 160 @staticmethod 161 def _process_copy_command(path): 162 file_paths = glob.glob(path) 163 for file_path in file_paths: 164 _LOGGER.info(file_path) 165 return file_paths 166 167 @staticmethod 168 def _convert_file_name_to_archive_name(file_name): 169 # File name is the name of the file on disk, whereas archive name is the name of that same file in the archive. 170 # For non-truncated files: /var/log/waagent.log on disk becomes var/log/waagent.log in archive 171 # (leading separator is removed by the archive). 172 # For truncated files: /var/lib/waagent/logcollector/truncated/var/log/syslog.1 on disk becomes 173 # truncated_var_log_syslog.1 in the archive. 174 if file_name.startswith(_TRUNCATED_FILES_DIR): 175 original_file_path = file_name[len(_TRUNCATED_FILES_DIR):].lstrip(os.path.sep) 176 archive_file_name = LogCollector._TRUNCATED_FILE_PREFIX + original_file_path.replace(os.path.sep, "_") 177 return archive_file_name 178 else: 179 return file_name.lstrip(os.path.sep) 180 181 @staticmethod 182 def _remove_uncollected_truncated_files(files_to_collect): 183 # After log collection is completed, see if there are any old truncated files which were not collected 184 # and remove them since they probably won't be collected in the future. This is possible when the 185 # original file got deleted, so there is no need to keep its truncated version anymore. 186 truncated_files = os.listdir(_TRUNCATED_FILES_DIR) 187 188 for file_path in truncated_files: 189 full_path = os.path.join(_TRUNCATED_FILES_DIR, file_path) 190 if full_path not in files_to_collect: 191 if os.path.isfile(full_path): 192 os.remove(full_path) 193 194 @staticmethod 195 def _expand_parameters(manifest_data): 196 _LOGGER.info("Using %s as $LIB_DIR", _AGENT_LIB_DIR) 197 _LOGGER.info("Using %s as $LOG_DIR", _EXTENSION_LOG_DIR) 198 _LOGGER.info("Using %s as $AGENT_LOG", _AGENT_LOG) 199 200 new_manifest = [] 201 for line in manifest_data: 202 new_line = line.replace("$LIB_DIR", _AGENT_LIB_DIR) 203 new_line = new_line.replace("$LOG_DIR", _EXTENSION_LOG_DIR) 204 new_line = new_line.replace("$AGENT_LOG", _AGENT_LOG) 205 new_manifest.append(new_line) 206 207 return new_manifest 208 209 def _process_manifest_file(self): 210 files_to_collect = set() 211 data = self._read_manifest() 212 manifest_entries = LogCollector._expand_parameters(data) 213 214 for entry in manifest_entries: 215 # The entry can be one of the four flavours: 216 # 1) ll,/etc/udev/rules.d -- list out contents of the folder and store to results file 217 # 2) echo,### Gathering Configuration Files ### -- print message to results file 218 # 3) copy,/var/lib/waagent/provisioned -- add file to list of files to be collected 219 # 4) diskinfo, -- ignore commands from manifest other than ll, echo, and copy for now 220 221 contents = entry.split(",") 222 if len(contents) != 2: 223 # If it's not a comment or an empty line, it's a malformed entry 224 if not entry.startswith("#") and len(entry.strip()) > 0: 225 _LOGGER.error("Couldn't parse \"%s\"", entry) 226 continue 227 228 command, value = contents 229 230 if command == "ll": 231 self._process_ll_command(value) 232 elif command == "echo": 233 self._process_echo_command(value) 234 elif command == "copy": 235 files_to_collect.update(self._process_copy_command(value)) 236 237 return files_to_collect 238 239 @staticmethod 240 def _truncate_large_file(file_path): 241 # Truncate large file to size limit (keep freshest entries of the file), copy file to a temporary location 242 # and update file path in list of files to collect 243 try: 244 # Binary files cannot be truncated, don't include large binary files 245 ext = os.path.splitext(file_path)[1] 246 if ext in [".gz", ".zip", ".xz"]: 247 _LOGGER.warning("Discarding large binary file %s", file_path) 248 return None 249 250 truncated_file_path = os.path.join(_TRUNCATED_FILES_DIR, file_path.replace(os.path.sep, "_")) 251 if os.path.exists(truncated_file_path): 252 original_file_mtime = os.path.getmtime(file_path) 253 truncated_file_mtime = os.path.getmtime(truncated_file_path) 254 255 # If the original file hasn't been updated since the truncated file, it means there were no changes 256 # and we don't need to truncate it again. 257 if original_file_mtime < truncated_file_mtime: 258 return truncated_file_path 259 260 # Get the last N bytes of the file 261 with open(truncated_file_path, "w+") as fh: 262 LogCollector._run_shell_command(["tail", "-c", str(_FILE_SIZE_LIMIT), file_path], stdout=fh) 263 264 return truncated_file_path 265 except OSError as e: 266 _LOGGER.error("Failed to truncate large file: %s", ustr(e)) 267 return None 268 269 def _get_file_priority(self, file_entry): 270 # The sooner the file appears in the must collect list, the bigger its priority. 271 # Priority is higher the lower the number (0 is highest priority). 272 try: 273 return self._must_collect_files.index(file_entry) 274 except ValueError: 275 # Doesn't matter, file is not in the must collect list, assign a low priority 276 return 999999999 277 278 def _get_priority_files_list(self, file_list): 279 # Given a list of files to collect, determine if they show up in the must collect list and build a priority 280 # queue. The queue will determine the order in which the files are collected, highest priority files first. 281 priority_file_queue = [] 282 for file_entry in file_list: 283 priority = self._get_file_priority(file_entry) 284 heappush(priority_file_queue, (priority, file_entry)) 285 286 return priority_file_queue 287 288 def _get_final_list_for_archive(self, priority_file_queue): 289 # Given a priority queue of files to collect, add one by one while the archive size is under the size limit. 290 # If a single file is over the file size limit, truncate it before adding it to the archive. 291 _LOGGER.info("### Preparing list of files to add to archive ###") 292 total_uncompressed_size = 0 293 final_files_to_collect = [] 294 295 while priority_file_queue: 296 file_path = heappop(priority_file_queue)[1] # (priority, file_path) 297 file_size = min(os.path.getsize(file_path), _FILE_SIZE_LIMIT) 298 299 if total_uncompressed_size + file_size > _UNCOMPRESSED_ARCHIVE_SIZE_LIMIT: 300 _LOGGER.warning("Archive too big, done with adding files.") 301 break 302 303 if os.path.getsize(file_path) <= _FILE_SIZE_LIMIT: 304 final_files_to_collect.append(file_path) 305 _LOGGER.info("Adding file %s, size %s b", file_path, file_size) 306 else: 307 truncated_file_path = self._truncate_large_file(file_path) 308 if truncated_file_path: 309 _LOGGER.info("Adding truncated file %s, size %s b", truncated_file_path, file_size) 310 final_files_to_collect.append(truncated_file_path) 311 312 total_uncompressed_size += file_size 313 314 _LOGGER.info("Uncompressed archive size is %s b", total_uncompressed_size) 315 316 return final_files_to_collect 317 318 def _create_list_of_files_to_collect(self): 319 # The final list of files to be collected by zip is created in three steps: 320 # 1) Parse given manifest file, expanding wildcards and keeping a list of files that exist on disk 321 # 2) Assign those files a priority depending on whether they are in the must collect file list. 322 # 3) In priority order, add files to the final list to be collected, until the size of the archive is under 323 # the size limit. 324 parsed_file_paths = self._process_manifest_file() 325 prioritized_file_paths = self._get_priority_files_list(parsed_file_paths) 326 files_to_collect = self._get_final_list_for_archive(prioritized_file_paths) 327 return files_to_collect 328 329 def collect_logs_and_get_archive(self): 330 """ 331 Public method that collects necessary log files in a compressed zip archive. 332 :return: Returns the path of the collected compressed archive 333 """ 334 files_to_collect = [] 335 336 try: 337 # Clear previous run's output and create base directories if they don't exist already. 338 self._create_base_dirs() 339 LogCollector._reset_file(OUTPUT_RESULTS_FILE_PATH) 340 start_time = datetime.utcnow() 341 _LOGGER.info("Starting log collection at %s", start_time.strftime("%Y-%m-%dT%H:%M:%SZ")) 342 _LOGGER.info("Using log collection mode %s", "full" if self._is_full_mode else "normal") 343 344 files_to_collect = self._create_list_of_files_to_collect() 345 _LOGGER.info("### Creating compressed archive ###") 346 347 with zipfile.ZipFile(COMPRESSED_ARCHIVE_PATH, "w", compression=zipfile.ZIP_DEFLATED) as compressed_archive: 348 for file_to_collect in files_to_collect: 349 archive_file_name = LogCollector._convert_file_name_to_archive_name(file_to_collect) 350 compressed_archive.write(file_to_collect.encode("utf-8"), arcname=archive_file_name) 351 352 compressed_archive_size = os.path.getsize(COMPRESSED_ARCHIVE_PATH) 353 _LOGGER.info("Successfully compressed files. Compressed archive size is %s b", compressed_archive_size) 354 355 end_time = datetime.utcnow() 356 duration = end_time - start_time 357 elapsed_ms = int(((duration.days * 24 * 60 * 60 + duration.seconds) * 1000) + (duration.microseconds / 1000.0)) 358 _LOGGER.info("Finishing log collection at %s", end_time.utcnow().strftime("%Y-%m-%dT%H:%M:%SZ")) 359 _LOGGER.info("Elapsed time: %s ms", elapsed_ms) 360 361 compressed_archive.write(OUTPUT_RESULTS_FILE_PATH.encode("utf-8"), arcname="results.txt") 362 363 return COMPRESSED_ARCHIVE_PATH 364 except Exception as e: 365 msg = "Failed to collect logs: {0}".format(ustr(e)) 366 _LOGGER.error(msg) 367 368 raise 369 finally: 370 self._remove_uncollected_truncated_files(files_to_collect) 371