1# 2# TeamCity UI Implementation 3# 4# Implements a TeamCity frontend for the BitBake utility, via service messages. 5# See https://www.jetbrains.com/help/teamcity/build-script-interaction-with-teamcity.html 6# 7# Based on ncurses.py and knotty.py, variously by Michael Lauer and Richard Purdie 8# 9# Copyright (C) 2006 Michael 'Mickey' Lauer 10# Copyright (C) 2006-2012 Richard Purdie 11# Copyright (C) 2018-2020 Agilent Technologies, Inc. 12# 13# SPDX-License-Identifier: GPL-2.0-only 14# 15# Author: Chris Laplante <chris.laplante@agilent.com> 16 17from __future__ import division 18 19import datetime 20import logging 21import math 22import os 23import re 24import sys 25import xmlrpc.client 26from collections import deque 27 28import bb 29import bb.build 30import bb.command 31import bb.cooker 32import bb.event 33import bb.exceptions 34import bb.runqueue 35from bb.ui import uihelper 36 37logger = logging.getLogger("BitBake") 38 39 40class TeamCityUI: 41 def __init__(self): 42 self._block_stack = [] 43 self._last_progress_state = None 44 45 @classmethod 46 def escape_service_value(cls, value): 47 """ 48 Escape a value for inclusion in a service message. TeamCity uses the vertical pipe character for escaping. 49 See: https://confluence.jetbrains.com/display/TCD10/Build+Script+Interaction+with+TeamCity#BuildScriptInteractionwithTeamCity-Escapedvalues 50 """ 51 return re.sub(r"(['|\[\]])", r"|\1", value).replace("\n", "|n").replace("\r", "|r") 52 53 @classmethod 54 def emit_service_message(cls, message_type, **kwargs): 55 print(cls.format_service_message(message_type, **kwargs), flush=True) 56 57 @classmethod 58 def format_service_message(cls, message_type, **kwargs): 59 payload = " ".join(["{0}='{1}'".format(k, cls.escape_service_value(v)) for k, v in kwargs.items()]) 60 return "##teamcity[{0} {1}]".format(message_type, payload) 61 62 @classmethod 63 def emit_simple_service_message(cls, message_type, message): 64 print(cls.format_simple_service_message(message_type, message), flush=True) 65 66 @classmethod 67 def format_simple_service_message(cls, message_type, message): 68 return "##teamcity[{0} '{1}']".format(message_type, cls.escape_service_value(message)) 69 70 @classmethod 71 def format_build_message(cls, text, status): 72 return cls.format_service_message("message", text=text, status=status) 73 74 def block_start(self, name): 75 self._block_stack.append(name) 76 self.emit_service_message("blockOpened", name=name) 77 78 def block_end(self): 79 if self._block_stack: 80 name = self._block_stack.pop() 81 self.emit_service_message("blockClosed", name=name) 82 83 def progress(self, message, percent, extra=None): 84 now = datetime.datetime.now() 85 percent = "{0: >3.0f}".format(percent) 86 87 report = False 88 if not self._last_progress_state \ 89 or (self._last_progress_state[0] == message 90 and self._last_progress_state[1] != percent 91 and (now - self._last_progress_state[2]).microseconds >= 5000) \ 92 or self._last_progress_state[0] != message: 93 report = True 94 self._last_progress_state = (message, percent, now) 95 96 if report or percent in [0, 100]: 97 self.emit_simple_service_message("progressMessage", "{0}: {1}%{2}".format(message, percent, extra or "")) 98 99 100class TeamcityLogFormatter(logging.Formatter): 101 def format(self, record): 102 details = "" 103 if hasattr(record, 'bb_exc_formatted'): 104 details = ''.join(record.bb_exc_formatted) 105 elif hasattr(record, 'bb_exc_info'): 106 etype, value, tb = record.bb_exc_info 107 formatted = bb.exceptions.format_exception(etype, value, tb, limit=5) 108 details = ''.join(formatted) 109 110 if record.levelno in [bb.msg.BBLogFormatter.ERROR, bb.msg.BBLogFormatter.CRITICAL]: 111 # ERROR gets a separate errorDetails field 112 msg = TeamCityUI.format_service_message("message", text=record.getMessage(), status="ERROR", 113 errorDetails=details) 114 else: 115 payload = record.getMessage() 116 if details: 117 payload += "\n" + details 118 if record.levelno == bb.msg.BBLogFormatter.PLAIN: 119 msg = payload 120 elif record.levelno == bb.msg.BBLogFormatter.WARNING: 121 msg = TeamCityUI.format_service_message("message", text=payload, status="WARNING") 122 else: 123 msg = TeamCityUI.format_service_message("message", text=payload, status="NORMAL") 124 125 return msg 126 127 128_evt_list = ["bb.runqueue.runQueueExitWait", "bb.event.LogExecTTY", "logging.LogRecord", 129 "bb.build.TaskFailed", "bb.build.TaskBase", "bb.event.ParseStarted", 130 "bb.event.ParseProgress", "bb.event.ParseCompleted", "bb.event.CacheLoadStarted", 131 "bb.event.CacheLoadProgress", "bb.event.CacheLoadCompleted", "bb.command.CommandFailed", 132 "bb.command.CommandExit", "bb.command.CommandCompleted", "bb.cooker.CookerExit", 133 "bb.event.MultipleProviders", "bb.event.NoProvider", "bb.runqueue.sceneQueueTaskStarted", 134 "bb.runqueue.runQueueTaskStarted", "bb.runqueue.runQueueTaskFailed", "bb.runqueue.sceneQueueTaskFailed", 135 "bb.event.BuildBase", "bb.build.TaskStarted", "bb.build.TaskSucceeded", "bb.build.TaskFailedSilent", 136 "bb.build.TaskProgress", "bb.event.ProcessStarted", "bb.event.ProcessProgress", "bb.event.ProcessFinished"] 137 138 139def _log_settings_from_server(server): 140 # Get values of variables which control our output 141 includelogs, error = server.runCommand(["getVariable", "BBINCLUDELOGS"]) 142 if error: 143 logger.error("Unable to get the value of BBINCLUDELOGS variable: %s" % error) 144 raise BaseException(error) 145 loglines, error = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"]) 146 if error: 147 logger.error("Unable to get the value of BBINCLUDELOGS_LINES variable: %s" % error) 148 raise BaseException(error) 149 return includelogs, loglines 150 151 152def main(server, eventHandler, params): 153 params.updateToServer(server, os.environ.copy()) 154 155 includelogs, loglines = _log_settings_from_server(server) 156 157 ui = TeamCityUI() 158 159 helper = uihelper.BBUIHelper() 160 161 console = logging.StreamHandler(sys.stdout) 162 errconsole = logging.StreamHandler(sys.stderr) 163 format = TeamcityLogFormatter() 164 if params.options.quiet == 0: 165 forcelevel = None 166 elif params.options.quiet > 2: 167 forcelevel = bb.msg.BBLogFormatter.ERROR 168 else: 169 forcelevel = bb.msg.BBLogFormatter.WARNING 170 console.setFormatter(format) 171 errconsole.setFormatter(format) 172 if not bb.msg.has_console_handler(logger): 173 logger.addHandler(console) 174 logger.addHandler(errconsole) 175 176 if params.options.remote_server and params.options.kill_server: 177 server.terminateServer() 178 return 179 180 if params.observe_only: 181 logger.error("Observe-only mode not supported in this UI") 182 return 1 183 184 llevel, debug_domains = bb.msg.constructLogOptions() 185 server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list]) 186 187 try: 188 params.updateFromServer(server) 189 cmdline = params.parseActions() 190 if not cmdline: 191 logger.error("No task given") 192 return 1 193 if 'msg' in cmdline and cmdline['msg']: 194 logger.error(cmdline['msg']) 195 return 1 196 cmdline = cmdline['action'] 197 ret, error = server.runCommand(cmdline) 198 if error: 199 logger.error("{0}: {1}".format(cmdline, error)) 200 return 1 201 elif not ret: 202 logger.error("Couldn't get default commandline: {0}".format(re)) 203 return 1 204 except xmlrpc.client.Fault as x: 205 logger.error("XMLRPC Fault getting commandline: {0}".format(x)) 206 return 1 207 208 active_process_total = None 209 is_tasks_running = False 210 211 while True: 212 try: 213 event = eventHandler.waitEvent(0.25) 214 if not event: 215 continue 216 217 helper.eventHandler(event) 218 219 if isinstance(event, bb.build.TaskBase): 220 logger.info(event._message) 221 if isinstance(event, logging.LogRecord): 222 # Don't report sstate failures as errors, since Yocto will just run the tasks for real 223 if event.msg == "No suitable staging package found" or (event.msg.startswith( 224 "Fetcher failure: Unable to find file") and "downloadfilename" in event.msg and "sstate" in event.msg): 225 event.levelno = bb.msg.BBLogFormatter.WARNING 226 if event.taskpid != 0: 227 # For "normal" logging conditions, don't show note logs from tasks 228 # but do show them if the user has changed the default log level to 229 # include verbose/debug messages 230 if event.levelno <= bb.msg.BBLogFormatter.NOTE and (event.levelno < llevel or ( 231 event.levelno == bb.msg.BBLogFormatter.NOTE and llevel != bb.msg.BBLogFormatter.VERBOSE)): 232 continue 233 234 # Prefix task messages with recipe/task 235 if event.taskpid in helper.running_tasks and event.levelno != bb.msg.BBLogFormatter.PLAIN: 236 taskinfo = helper.running_tasks[event.taskpid] 237 event.msg = taskinfo['title'] + ': ' + event.msg 238 if hasattr(event, 'fn'): 239 event.msg = event.fn + ': ' + event.msg 240 logger.handle(event) 241 if isinstance(event, bb.build.TaskFailedSilent): 242 logger.warning("Logfile for failed setscene task is %s" % event.logfile) 243 continue 244 if isinstance(event, bb.build.TaskFailed): 245 rt = "{0}-{1}:{2}".format(event.pn, event.pv.replace("AUTOINC", "0"), event.task) 246 247 logfile = event.logfile 248 if not logfile or not os.path.exists(logfile): 249 TeamCityUI.emit_service_message("buildProblem", description="{0}\nUnknown failure (no log file available)".format(rt)) 250 if not event.task.endswith("_setscene"): 251 server.runCommand(["stateForceShutdown"]) 252 continue 253 254 details = deque(maxlen=loglines) 255 error_lines = [] 256 if includelogs and not event.errprinted: 257 with open(logfile, "r") as f: 258 while True: 259 line = f.readline() 260 if not line: 261 break 262 line = line.rstrip() 263 details.append(' | %s' % line) 264 # TODO: a less stupid check for errors 265 if (event.task == "do_compile") and ("error:" in line): 266 error_lines.append(line) 267 268 if error_lines: 269 TeamCityUI.emit_service_message("compilationStarted", compiler=rt) 270 for line in error_lines: 271 TeamCityUI.emit_service_message("message", text=line, status="ERROR") 272 TeamCityUI.emit_service_message("compilationFinished", compiler=rt) 273 else: 274 TeamCityUI.emit_service_message("buildProblem", description=rt) 275 276 err = "Logfile of failure stored in: %s" % logfile 277 if details: 278 ui.block_start("{0} task log".format(rt)) 279 # TeamCity seems to choke on service messages longer than about 63800 characters, so if error 280 # details is longer than, say, 60000, batch it up into several messages. 281 first_message = True 282 while details: 283 detail_len = 0 284 batch = deque() 285 while details and detail_len < 60000: 286 # TODO: This code doesn't bother to handle lines that themselves are extremely long. 287 line = details.popleft() 288 batch.append(line) 289 detail_len += len(line) 290 291 if first_message: 292 batch.appendleft("Log data follows:") 293 first_message = False 294 TeamCityUI.emit_service_message("message", text=err, status="ERROR", 295 errorDetails="\n".join(batch)) 296 else: 297 TeamCityUI.emit_service_message("message", text="[continued]", status="ERROR", 298 errorDetails="\n".join(batch)) 299 ui.block_end() 300 else: 301 TeamCityUI.emit_service_message("message", text=err, status="ERROR", errorDetails="") 302 303 if not event.task.endswith("_setscene"): 304 server.runCommand(["stateForceShutdown"]) 305 306 if isinstance(event, bb.event.ProcessStarted): 307 if event.processname in ["Initialising tasks", "Checking sstate mirror object availability"]: 308 active_process_total = event.total 309 ui.block_start(event.processname) 310 if isinstance(event, bb.event.ProcessFinished): 311 if event.processname in ["Initialising tasks", "Checking sstate mirror object availability"]: 312 ui.progress(event.processname, 100) 313 ui.block_end() 314 if isinstance(event, bb.event.ProcessProgress): 315 if event.processname in ["Initialising tasks", 316 "Checking sstate mirror object availability"] and active_process_total != 0: 317 ui.progress(event.processname, event.progress * 100 / active_process_total) 318 if isinstance(event, bb.event.CacheLoadStarted): 319 ui.block_start("Loading cache") 320 if isinstance(event, bb.event.CacheLoadProgress): 321 if event.total != 0: 322 ui.progress("Loading cache", math.floor(event.current * 100 / event.total)) 323 if isinstance(event, bb.event.CacheLoadCompleted): 324 ui.progress("Loading cache", 100) 325 ui.block_end() 326 if isinstance(event, bb.event.ParseStarted): 327 ui.block_start("Parsing recipes and checking upstream revisions") 328 if isinstance(event, bb.event.ParseProgress): 329 if event.total != 0: 330 ui.progress("Parsing recipes", math.floor(event.current * 100 / event.total)) 331 if isinstance(event, bb.event.ParseCompleted): 332 ui.progress("Parsing recipes", 100) 333 ui.block_end() 334 if isinstance(event, bb.command.CommandCompleted): 335 return 336 if isinstance(event, bb.command.CommandFailed): 337 logger.error(str(event)) 338 return 1 339 if isinstance(event, bb.event.MultipleProviders): 340 logger.warning(str(event)) 341 continue 342 if isinstance(event, bb.event.NoProvider): 343 logger.error(str(event)) 344 continue 345 if isinstance(event, bb.command.CommandExit): 346 return 347 if isinstance(event, bb.cooker.CookerExit): 348 return 349 if isinstance(event, bb.runqueue.sceneQueueTaskStarted): 350 if not is_tasks_running: 351 is_tasks_running = True 352 ui.block_start("Running tasks") 353 if event.stats.total != 0: 354 ui.progress("Running setscene tasks", ( 355 event.stats.completed + event.stats.active + event.stats.failed + 1) * 100 / event.stats.total) 356 if isinstance(event, bb.runqueue.runQueueTaskStarted): 357 if not is_tasks_running: 358 is_tasks_running = True 359 ui.block_start("Running tasks") 360 if event.stats.total != 0: 361 pseudo_total = event.stats.total - event.stats.skipped 362 pseudo_complete = event.stats.completed + event.stats.active - event.stats.skipped + event.stats.failed + 1 363 # TODO: sometimes this gives over 100% 364 ui.progress("Running runqueue tasks", (pseudo_complete) * 100 / pseudo_total, 365 " ({0}/{1})".format(pseudo_complete, pseudo_total)) 366 if isinstance(event, bb.runqueue.sceneQueueTaskFailed): 367 logger.warning(str(event)) 368 continue 369 if isinstance(event, bb.runqueue.runQueueTaskFailed): 370 logger.error(str(event)) 371 return 1 372 if isinstance(event, bb.event.LogExecTTY): 373 pass 374 except EnvironmentError as ioerror: 375 # ignore interrupted io 376 if ioerror.args[0] == 4: 377 pass 378 except Exception as ex: 379 logger.error(str(ex)) 380 381 # except KeyboardInterrupt: 382 # if shutdown == 2: 383 # mw.appendText("Third Keyboard Interrupt, exit.\n") 384 # exitflag = True 385 # if shutdown == 1: 386 # mw.appendText("Second Keyboard Interrupt, stopping...\n") 387 # _, error = server.runCommand(["stateForceShutdown"]) 388 # if error: 389 # print("Unable to cleanly stop: %s" % error) 390 # if shutdown == 0: 391 # mw.appendText("Keyboard Interrupt, closing down...\n") 392 # _, error = server.runCommand(["stateShutdown"]) 393 # if error: 394 # print("Unable to cleanly shutdown: %s" % error) 395 # shutdown = shutdown + 1 396 # pass 397