1""" 2Defines handlers for communicating with a buildlogger server. 3""" 4 5from __future__ import absolute_import 6 7import functools 8import json 9import os 10import threading 11 12import requests 13 14from . import handlers 15from .. import config as _config 16 17 18CREATE_BUILD_ENDPOINT = "/build" 19APPEND_GLOBAL_LOGS_ENDPOINT = "/build/%(build_id)s" 20CREATE_TEST_ENDPOINT = "/build/%(build_id)s/test" 21APPEND_TEST_LOGS_ENDPOINT = "/build/%(build_id)s/test/%(test_id)s" 22 23_BUILDLOGGER_CONFIG = os.getenv("BUILDLOGGER_CREDENTIALS", "mci.buildlogger") 24 25_SEND_AFTER_LINES = 2000 26_SEND_AFTER_SECS = 10 27 28# Initialized by resmokelib.logging.loggers.configure_loggers() 29BUILDLOGGER_FALLBACK = None 30 31_INCOMPLETE_LOG_OUTPUT = threading.Event() 32 33 34def is_log_output_incomplete(): # noqa: D205,D400 35 """Return true if we failed to write all of the log output to the buildlogger server, and return 36 false otherwise. 37 """ 38 return _INCOMPLETE_LOG_OUTPUT.is_set() 39 40 41def set_log_output_incomplete(): 42 """Indicate that we failed to write all of the log output to the buildlogger server.""" 43 _INCOMPLETE_LOG_OUTPUT.set() 44 45 46def _log_on_error(func): 47 """ 48 A decorator that causes any exceptions to be logged by the 49 "buildlogger" Logger instance. 50 51 Returns the wrapped function's return value, or None if an error 52 was encountered. 53 """ 54 55 @functools.wraps(func) 56 def wrapper(*args, **kwargs): 57 try: 58 return func(*args, **kwargs) 59 except requests.HTTPError as err: 60 BUILDLOGGER_FALLBACK.error("Encountered an HTTP error: %s", err) 61 except requests.RequestException as err: 62 BUILDLOGGER_FALLBACK.error("Encountered a network error: %s", err) 63 except: # pylint: disable=bare-except 64 BUILDLOGGER_FALLBACK.exception("Encountered an error.") 65 return None 66 67 return wrapper 68 69 70class _LogsSplitter(object): 71 """Class with static methods used to split list of log lines into smaller batches.""" 72 73 @staticmethod 74 def split_logs(log_lines, max_size): 75 """ 76 Splits the log lines into batches of size less than or equal to max_size. 77 78 Args: 79 log_lines: A list of log lines. 80 max_size: The maximum size in bytes a batch of log lines can have in JSON. 81 Returns: 82 A list of list of log lines. Each item is a list is a list of log lines 83 satisfying the size requirement. 84 """ 85 if not max_size: 86 return [log_lines] 87 88 def line_size(line): 89 """ 90 Computes the encoded JSON size of a log line as part of an array. 91 2 is added to each string size to account for the array representation of the logs, 92 as each line is preceded by a '[' or a space and followed by a ',' or a ']'. 93 """ 94 return len(json.dumps(line, encoding="utf-8")) + 2 95 96 curr_logs = [] 97 curr_logs_size = 0 98 split_logs = [] 99 for line in log_lines: 100 size = line_size(line) 101 if curr_logs_size + size > max_size: 102 split_logs.append(curr_logs) 103 curr_logs = [] 104 curr_logs_size = 0 105 curr_logs.append(line) 106 curr_logs_size += size 107 split_logs.append(curr_logs) 108 return split_logs 109 110 111class _BaseBuildloggerHandler(handlers.BufferedHandler): 112 """ 113 Base class of the buildlogger handler for the global logs and the 114 handler for the test logs. 115 """ 116 117 def __init__(self, 118 build_config, 119 endpoint, 120 capacity=_SEND_AFTER_LINES, 121 interval_secs=_SEND_AFTER_SECS): 122 """ 123 Initializes the buildlogger handler with the build id and 124 credentials. 125 """ 126 127 handlers.BufferedHandler.__init__(self, capacity, interval_secs) 128 129 username = build_config["username"] 130 password = build_config["password"] 131 self.http_handler = handlers.HTTPHandler(_config.BUILDLOGGER_URL, username, password) 132 133 self.endpoint = endpoint 134 self.retry_buffer = [] 135 self.max_size = None 136 137 def process_record(self, record): 138 """ 139 Returns a tuple of the time the log record was created, and the 140 message because the buildlogger expects the log messages 141 formatted in JSON as: 142 143 [ [ <log-time-1>, <log-message-1> ], 144 [ <log-time-2>, <log-message-2> ], 145 ... ] 146 """ 147 msg = self.format(record) 148 return (record.created, msg) 149 150 def post(self, *args, **kwargs): 151 """ 152 Convenience method for subclasses to use when making POST requests. 153 """ 154 return self.http_handler.post(*args, **kwargs) 155 156 def _append_logs(self, log_lines): 157 """ 158 Sends a POST request to the handlers endpoint with the logs that have been captured. 159 160 Returns: 161 The number of log lines that have been successfully sent. 162 """ 163 lines_sent = 0 164 for chunk in _LogsSplitter.split_logs(log_lines, self.max_size): 165 chunk_lines_sent = self.__append_logs_chunk(chunk) 166 lines_sent += chunk_lines_sent 167 if chunk_lines_sent < len(chunk): 168 # Not all lines have been sent. We stop here. 169 break 170 return lines_sent 171 172 def __append_logs_chunk(self, log_lines_chunk): 173 """ 174 Sends a log lines chunk, handles 413 Request Entity Too Large errors and retries 175 if necessary. 176 177 Returns: 178 The number of log lines that have been successfully sent. 179 """ 180 try: 181 self.post(self.endpoint, data=log_lines_chunk) 182 return len(log_lines_chunk) 183 except requests.HTTPError as err: 184 # Handle the "Request Entity Too Large" error, set the max size and retry. 185 if err.response.status_code == requests.codes.request_entity_too_large: 186 response_data = err.response.json() 187 if isinstance(response_data, dict) and "max_size" in response_data: 188 new_max_size = response_data["max_size"] 189 if self.max_size and new_max_size >= self.max_size: 190 BUILDLOGGER_FALLBACK.exception( 191 "Received an HTTP 413 code, but already had max_size set") 192 return 0 193 BUILDLOGGER_FALLBACK.warning( 194 "Received an HTTP 413 code, updating the request max_size to %s", 195 new_max_size) 196 self.max_size = new_max_size 197 return self._append_logs(log_lines_chunk) 198 BUILDLOGGER_FALLBACK.error("Encountered an HTTP error: %s", err) 199 except requests.RequestException as err: 200 BUILDLOGGER_FALLBACK.error("Encountered a network error: %s", err) 201 except: # pylint: disable=bare-except 202 BUILDLOGGER_FALLBACK.exception("Encountered an error.") 203 return 0 204 205 def _flush_buffer_with_lock(self, buf, close_called): 206 """ 207 Ensures all logging output has been flushed to the buildlogger 208 server. 209 210 If _append_logs() returns false, then the log messages are added 211 to a separate buffer and retried the next time flush() is 212 called. 213 """ 214 215 self.retry_buffer.extend(buf) 216 217 nb_sent = self._append_logs(self.retry_buffer) 218 if nb_sent: 219 self.retry_buffer = self.retry_buffer[nb_sent:] 220 if close_called and self.retry_buffer: 221 # The request to the logkeeper returned an error. We discard the log output rather than 222 # writing the messages to the fallback logkeeper to avoid putting additional pressure on 223 # the Evergreen database. 224 BUILDLOGGER_FALLBACK.warning( 225 "Failed to flush all log output (%d messages) to logkeeper.", len( 226 self.retry_buffer)) 227 228 # We set a flag to indicate that we failed to flush all log output to logkeeper so 229 # resmoke.py can exit with a special return code. 230 set_log_output_incomplete() 231 232 self.retry_buffer = [] 233 234 235class BuildloggerTestHandler(_BaseBuildloggerHandler): 236 """ 237 Buildlogger handler for the test logs. 238 """ 239 240 def __init__(self, build_config, build_id, test_id, 241 capacity=_SEND_AFTER_LINES, interval_secs=_SEND_AFTER_SECS): 242 """Initializes the buildlogger handler with the credentials, build id, and test id.""" 243 endpoint = APPEND_TEST_LOGS_ENDPOINT % { 244 "build_id": build_id, 245 "test_id": test_id, 246 } 247 _BaseBuildloggerHandler.__init__(self, build_config, endpoint, capacity, interval_secs) 248 249 @_log_on_error 250 def _finish_test(self, failed=False): 251 """ 252 Sends a POST request to the APPEND_TEST_LOGS_ENDPOINT with the 253 test status. 254 """ 255 self.post(self.endpoint, headers={ 256 "X-Sendlogs-Test-Done": "true", 257 "X-Sendlogs-Test-Failed": "true" if failed else "false", 258 }) 259 260 def close(self): 261 """ 262 Closes the buildlogger handler. 263 """ 264 265 _BaseBuildloggerHandler.close(self) 266 267 # TODO: pass the test status (success/failure) to this method 268 self._finish_test() 269 270 271class BuildloggerGlobalHandler(_BaseBuildloggerHandler): 272 """ 273 Buildlogger handler for the global logs. 274 """ 275 276 def __init__(self, build_config, build_id, 277 capacity=_SEND_AFTER_LINES, interval_secs=_SEND_AFTER_SECS): 278 """Initializes the buildlogger handler with the credentials and build id.""" 279 endpoint = APPEND_GLOBAL_LOGS_ENDPOINT % {"build_id": build_id} 280 _BaseBuildloggerHandler.__init__(self, build_config, endpoint, capacity, interval_secs) 281 282 283class BuildloggerServer(object): 284 """A remote server to which build logs can be sent. 285 286 It is used to retrieve handlers that can then be added to logger 287 instances to send the log to the servers. 288 """ 289 290 @_log_on_error 291 def __init__(self): 292 tmp_globals = {} 293 self.config = {} 294 execfile(_BUILDLOGGER_CONFIG, tmp_globals, self.config) 295 296 # Rename "slavename" to "username" if present. 297 if "slavename" in self.config and "username" not in self.config: 298 self.config["username"] = self.config["slavename"] 299 del self.config["slavename"] 300 301 # Rename "passwd" to "password" if present. 302 if "passwd" in self.config and "password" not in self.config: 303 self.config["password"] = self.config["passwd"] 304 del self.config["passwd"] 305 306 @_log_on_error 307 def new_build_id(self, suffix): 308 """ 309 Returns a new build id for sending global logs to. 310 """ 311 username = self.config["username"] 312 password = self.config["password"] 313 builder = "%s_%s" % (self.config["builder"], suffix) 314 build_num = int(self.config["build_num"]) 315 316 handler = handlers.HTTPHandler(url_root=_config.BUILDLOGGER_URL, username=username, 317 password=password, should_retry=True) 318 319 response = handler.post(CREATE_BUILD_ENDPOINT, data={ 320 "builder": builder, 321 "buildnum": build_num, 322 "task_id": _config.EVERGREEN_TASK_ID, 323 }) 324 325 return response["id"] 326 327 @_log_on_error 328 def new_test_id(self, build_id, test_filename, test_command): 329 """Return a new test id for sending test logs to.""" 330 handler = handlers.HTTPHandler(url_root=_config.BUILDLOGGER_URL, 331 username=self.config["username"], 332 password=self.config["password"], should_retry=True) 333 334 endpoint = CREATE_TEST_ENDPOINT % {"build_id": build_id} 335 response = handler.post(endpoint, data={ 336 "test_filename": test_filename, 337 "command": test_command, 338 "phase": self.config.get("build_phase", "unknown"), 339 "task_id": _config.EVERGREEN_TASK_ID, 340 }) 341 342 return response["id"] 343 344 def get_global_handler(self, build_id, handler_info): 345 return BuildloggerGlobalHandler(self.config, build_id, **handler_info) 346 347 def get_test_handler(self, build_id, test_id, handler_info): 348 return BuildloggerTestHandler(self.config, build_id, test_id, **handler_info) 349 350 @staticmethod 351 def get_build_log_url(build_id): 352 base_url = _config.BUILDLOGGER_URL.rstrip("/") 353 endpoint = APPEND_GLOBAL_LOGS_ENDPOINT % {"build_id": build_id} 354 return "%s/%s" % (base_url, endpoint.strip("/")) 355 356 @staticmethod 357 def get_test_log_url(build_id, test_id): 358 base_url = _config.BUILDLOGGER_URL.rstrip("/") 359 endpoint = APPEND_TEST_LOGS_ENDPOINT % {"build_id": build_id, "test_id": test_id} 360 return "%s/%s" % (base_url, endpoint.strip("/")) 361