1# 2# BitBake ToasterUI Implementation 3# based on (No)TTY UI Implementation by Richard Purdie 4# 5# Handling output to TTYs or files (no TTY) 6# 7# Copyright (C) 2006-2012 Richard Purdie 8# Copyright (C) 2013 Intel Corporation 9# 10# SPDX-License-Identifier: GPL-2.0-only 11# 12 13from __future__ import division 14import time 15import sys 16try: 17 import bb 18except RuntimeError as exc: 19 sys.exit(str(exc)) 20 21from bb.ui import uihelper 22from bb.ui.buildinfohelper import BuildInfoHelper 23 24import bb.msg 25import logging 26import os 27 28# pylint: disable=invalid-name 29# module properties for UI modules are read by bitbake and the contract should not be broken 30 31 32featureSet = [bb.cooker.CookerFeatures.HOB_EXTRA_CACHES, bb.cooker.CookerFeatures.BASEDATASTORE_TRACKING, bb.cooker.CookerFeatures.SEND_SANITYEVENTS] 33 34logger = logging.getLogger("ToasterLogger") 35interactive = sys.stdout.isatty() 36 37def _log_settings_from_server(server): 38 # Get values of variables which control our output 39 includelogs, error = server.runCommand(["getVariable", "BBINCLUDELOGS"]) 40 if error: 41 logger.error("Unable to get the value of BBINCLUDELOGS variable: %s", error) 42 raise BaseException(error) 43 loglines, error = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"]) 44 if error: 45 logger.error("Unable to get the value of BBINCLUDELOGS_LINES variable: %s", error) 46 raise BaseException(error) 47 consolelogfile, error = server.runCommand(["getVariable", "BB_CONSOLELOG"]) 48 if error: 49 logger.error("Unable to get the value of BB_CONSOLELOG variable: %s", error) 50 raise BaseException(error) 51 return consolelogfile 52 53# create a log file for a single build and direct the logger at it; 54# log file name is timestamped to the millisecond (depending 55# on system clock accuracy) to ensure it doesn't overlap with 56# other log file names 57# 58# returns (log file, path to log file) for a build 59def _open_build_log(log_dir): 60 format_str = "%(levelname)s: %(message)s" 61 62 now = time.time() 63 now_ms = int((now - int(now)) * 1000) 64 time_str = time.strftime('build_%Y%m%d_%H%M%S', time.localtime(now)) 65 log_file_name = time_str + ('.%d.log' % now_ms) 66 build_log_file_path = os.path.join(log_dir, log_file_name) 67 68 build_log = logging.FileHandler(build_log_file_path) 69 70 logformat = bb.msg.BBLogFormatter(format_str) 71 build_log.setFormatter(logformat) 72 73 bb.msg.addDefaultlogFilter(build_log) 74 logger.addHandler(build_log) 75 76 return (build_log, build_log_file_path) 77 78# stop logging to the build log if it exists 79def _close_build_log(build_log): 80 if build_log: 81 build_log.flush() 82 build_log.close() 83 logger.removeHandler(build_log) 84 85_evt_list = [ 86 "bb.build.TaskBase", 87 "bb.build.TaskFailed", 88 "bb.build.TaskFailedSilent", 89 "bb.build.TaskStarted", 90 "bb.build.TaskSucceeded", 91 "bb.command.CommandCompleted", 92 "bb.command.CommandExit", 93 "bb.command.CommandFailed", 94 "bb.cooker.CookerExit", 95 "bb.event.BuildInit", 96 "bb.event.BuildCompleted", 97 "bb.event.BuildStarted", 98 "bb.event.CacheLoadCompleted", 99 "bb.event.CacheLoadProgress", 100 "bb.event.CacheLoadStarted", 101 "bb.event.ConfigParsed", 102 "bb.event.DepTreeGenerated", 103 "bb.event.LogExecTTY", 104 "bb.event.MetadataEvent", 105 "bb.event.MultipleProviders", 106 "bb.event.NoProvider", 107 "bb.event.ParseCompleted", 108 "bb.event.ParseProgress", 109 "bb.event.ParseStarted", 110 "bb.event.RecipeParsed", 111 "bb.event.SanityCheck", 112 "bb.event.SanityCheckPassed", 113 "bb.event.TreeDataPreparationCompleted", 114 "bb.event.TreeDataPreparationStarted", 115 "bb.runqueue.runQueueTaskCompleted", 116 "bb.runqueue.runQueueTaskFailed", 117 "bb.runqueue.runQueueTaskSkipped", 118 "bb.runqueue.runQueueTaskStarted", 119 "bb.runqueue.sceneQueueTaskCompleted", 120 "bb.runqueue.sceneQueueTaskFailed", 121 "bb.runqueue.sceneQueueTaskStarted", 122 "logging.LogRecord"] 123 124def main(server, eventHandler, params): 125 # set to a logging.FileHandler instance when a build starts; 126 # see _open_build_log() 127 build_log = None 128 129 # set to the log path when a build starts 130 build_log_file_path = None 131 132 helper = uihelper.BBUIHelper() 133 134 if not params.observe_only: 135 params.updateToServer(server, os.environ.copy()) 136 params.updateFromServer(server) 137 138 # TODO don't use log output to determine when bitbake has started 139 # 140 # WARNING: this log handler cannot be removed, as localhostbecontroller 141 # relies on output in the toaster_ui.log file to determine whether 142 # the bitbake server has started, which only happens if 143 # this logger is setup here (see the TODO in the loop below) 144 console = logging.StreamHandler(sys.stdout) 145 format_str = "%(levelname)s: %(message)s" 146 formatter = bb.msg.BBLogFormatter(format_str) 147 bb.msg.addDefaultlogFilter(console) 148 console.setFormatter(formatter) 149 logger.addHandler(console) 150 logger.setLevel(logging.INFO) 151 llevel, debug_domains = bb.msg.constructLogOptions() 152 result, error = server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list]) 153 if not result or error: 154 logger.error("can't set event mask: %s", error) 155 return 1 156 157 # verify and warn 158 build_history_enabled = True 159 inheritlist, _ = server.runCommand(["getVariable", "INHERIT"]) 160 161 if not "buildhistory" in inheritlist.split(" "): 162 logger.warning("buildhistory is not enabled. Please enable INHERIT += \"buildhistory\" to see image details.") 163 build_history_enabled = False 164 165 if not "buildstats" in inheritlist.split(" "): 166 logger.warning("buildstats is not enabled. Please enable INHERIT += \"buildstats\" to generate build statistics.") 167 168 if not params.observe_only: 169 cmdline = params.parseActions() 170 if not cmdline: 171 print("Nothing to do. Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.") 172 return 1 173 if 'msg' in cmdline and cmdline['msg']: 174 logger.error(cmdline['msg']) 175 return 1 176 177 ret, error = server.runCommand(cmdline['action']) 178 if error: 179 logger.error("Command '%s' failed: %s" % (cmdline, error)) 180 return 1 181 elif not ret: 182 logger.error("Command '%s' failed: returned %s" % (cmdline, ret)) 183 return 1 184 185 # set to 1 when toasterui needs to shut down 186 main.shutdown = 0 187 188 interrupted = False 189 return_value = 0 190 errors = 0 191 warnings = 0 192 taskfailures = [] 193 first = True 194 195 buildinfohelper = BuildInfoHelper(server, build_history_enabled, 196 os.getenv('TOASTER_BRBE')) 197 198 # write our own log files into bitbake's log directory; 199 # we're only interested in the path to the parent directory of 200 # this file, as we're writing our own logs into the same directory 201 consolelogfile = _log_settings_from_server(server) 202 log_dir = os.path.dirname(consolelogfile) 203 bb.utils.mkdirhier(log_dir) 204 205 while True: 206 try: 207 event = eventHandler.waitEvent(0.25) 208 if first: 209 first = False 210 211 # TODO don't use log output to determine when bitbake has started 212 # 213 # this is the line localhostbecontroller needs to 214 # see in toaster_ui.log which it uses to decide whether 215 # the bitbake server has started... 216 logger.info("ToasterUI waiting for events") 217 218 if event is None: 219 if main.shutdown > 0: 220 # if shutting down, close any open build log first 221 _close_build_log(build_log) 222 223 break 224 continue 225 226 helper.eventHandler(event) 227 228 # pylint: disable=protected-access 229 # the code will look into the protected variables of the event; no easy way around this 230 231 if isinstance(event, bb.event.HeartbeatEvent): 232 continue 233 234 if isinstance(event, bb.event.ParseStarted): 235 if not (build_log and build_log_file_path): 236 build_log, build_log_file_path = _open_build_log(log_dir) 237 238 buildinfohelper.store_started_build() 239 buildinfohelper.save_build_log_file_path(build_log_file_path) 240 buildinfohelper.set_recipes_to_parse(event.total) 241 continue 242 243 # create a build object in buildinfohelper from either BuildInit 244 # (if available) or BuildStarted (for jethro and previous versions) 245 if isinstance(event, (bb.event.BuildStarted, bb.event.BuildInit)): 246 if not (build_log and build_log_file_path): 247 build_log, build_log_file_path = _open_build_log(log_dir) 248 249 buildinfohelper.save_build_targets(event) 250 buildinfohelper.save_build_log_file_path(build_log_file_path) 251 252 # get additional data from BuildStarted 253 if isinstance(event, bb.event.BuildStarted): 254 buildinfohelper.save_build_layers_and_variables() 255 continue 256 257 if isinstance(event, bb.event.ParseProgress): 258 buildinfohelper.set_recipes_parsed(event.current) 259 continue 260 261 if isinstance(event, bb.event.ParseCompleted): 262 buildinfohelper.set_recipes_parsed(event.total) 263 continue 264 265 if isinstance(event, (bb.build.TaskStarted, bb.build.TaskSucceeded, bb.build.TaskFailedSilent)): 266 buildinfohelper.update_and_store_task(event) 267 logger.info("Logfile for task %s", event.logfile) 268 continue 269 270 if isinstance(event, bb.build.TaskBase): 271 logger.info(event._message) 272 273 if isinstance(event, bb.event.LogExecTTY): 274 logger.info(event.msg) 275 continue 276 277 if isinstance(event, logging.LogRecord): 278 if event.levelno == -1: 279 event.levelno = formatter.ERROR 280 281 buildinfohelper.store_log_event(event) 282 283 if event.levelno >= formatter.ERROR: 284 errors = errors + 1 285 elif event.levelno == formatter.WARNING: 286 warnings = warnings + 1 287 288 # For "normal" logging conditions, don't show note logs from tasks 289 # but do show them if the user has changed the default log level to 290 # include verbose/debug messages 291 if event.taskpid != 0 and event.levelno <= formatter.NOTE: 292 continue 293 294 logger.handle(event) 295 continue 296 297 if isinstance(event, bb.build.TaskFailed): 298 buildinfohelper.update_and_store_task(event) 299 logfile = event.logfile 300 if logfile and os.path.exists(logfile): 301 bb.error("Logfile of failure stored in: %s" % logfile) 302 continue 303 304 # these events are unprocessed now, but may be used in the future to log 305 # timing and error informations from the parsing phase in Toaster 306 if isinstance(event, (bb.event.SanityCheckPassed, bb.event.SanityCheck)): 307 continue 308 if isinstance(event, bb.event.CacheLoadStarted): 309 continue 310 if isinstance(event, bb.event.CacheLoadProgress): 311 continue 312 if isinstance(event, bb.event.CacheLoadCompleted): 313 continue 314 if isinstance(event, bb.event.MultipleProviders): 315 logger.info(str(event)) 316 continue 317 318 if isinstance(event, bb.event.NoProvider): 319 errors = errors + 1 320 text = str(event) 321 logger.error(text) 322 buildinfohelper.store_log_error(text) 323 continue 324 325 if isinstance(event, bb.event.ConfigParsed): 326 continue 327 if isinstance(event, bb.event.RecipeParsed): 328 continue 329 330 # end of saved events 331 332 if isinstance(event, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted, bb.runqueue.runQueueTaskSkipped)): 333 buildinfohelper.store_started_task(event) 334 continue 335 336 if isinstance(event, bb.runqueue.runQueueTaskCompleted): 337 buildinfohelper.update_and_store_task(event) 338 continue 339 340 if isinstance(event, bb.runqueue.runQueueTaskFailed): 341 buildinfohelper.update_and_store_task(event) 342 taskfailures.append(event.taskstring) 343 logger.error(str(event)) 344 continue 345 346 if isinstance(event, (bb.runqueue.sceneQueueTaskCompleted, bb.runqueue.sceneQueueTaskFailed)): 347 buildinfohelper.update_and_store_task(event) 348 continue 349 350 351 if isinstance(event, (bb.event.TreeDataPreparationStarted, bb.event.TreeDataPreparationCompleted)): 352 continue 353 354 if isinstance(event, (bb.event.BuildCompleted, bb.command.CommandFailed)): 355 356 errorcode = 0 357 if isinstance(event, bb.command.CommandFailed): 358 errors += 1 359 errorcode = 1 360 logger.error(str(event)) 361 elif isinstance(event, bb.event.BuildCompleted): 362 buildinfohelper.scan_image_artifacts() 363 buildinfohelper.clone_required_sdk_artifacts() 364 365 # turn off logging to the current build log 366 _close_build_log(build_log) 367 368 # reset ready for next BuildStarted 369 build_log = None 370 371 # update the build info helper on BuildCompleted, not on CommandXXX 372 buildinfohelper.update_build_information(event, errors, warnings, taskfailures) 373 374 brbe = buildinfohelper.brbe 375 buildinfohelper.close(errorcode) 376 377 # we start a new build info 378 if params.observe_only: 379 logger.debug("ToasterUI prepared for new build") 380 errors = 0 381 warnings = 0 382 taskfailures = [] 383 buildinfohelper = BuildInfoHelper(server, build_history_enabled) 384 else: 385 main.shutdown = 1 386 387 logger.info("ToasterUI build done, brbe: %s", brbe) 388 break 389 390 if isinstance(event, (bb.command.CommandCompleted, 391 bb.command.CommandFailed, 392 bb.command.CommandExit)): 393 if params.observe_only: 394 errorcode = 0 395 else: 396 main.shutdown = 1 397 398 continue 399 400 if isinstance(event, bb.event.MetadataEvent): 401 if event.type == "SinglePackageInfo": 402 buildinfohelper.store_build_package_information(event) 403 elif event.type == "LayerInfo": 404 buildinfohelper.store_layer_info(event) 405 elif event.type == "BuildStatsList": 406 buildinfohelper.store_tasks_stats(event) 407 elif event.type == "ImagePkgList": 408 buildinfohelper.store_target_package_data(event) 409 elif event.type == "MissedSstate": 410 buildinfohelper.store_missed_state_tasks(event) 411 elif event.type == "SDKArtifactInfo": 412 buildinfohelper.scan_sdk_artifacts(event) 413 elif event.type == "SetBRBE": 414 buildinfohelper.brbe = buildinfohelper._get_data_from_event(event) 415 elif event.type == "TaskArtifacts": 416 buildinfohelper.scan_task_artifacts(event) 417 elif event.type == "OSErrorException": 418 logger.error(event) 419 else: 420 logger.error("Unprocessed MetadataEvent %s", event.type) 421 continue 422 423 if isinstance(event, bb.cooker.CookerExit): 424 # shutdown when bitbake server shuts down 425 main.shutdown = 1 426 continue 427 428 if isinstance(event, bb.event.DepTreeGenerated): 429 buildinfohelper.store_dependency_information(event) 430 continue 431 432 logger.warning("Unknown event: %s", event) 433 return_value += 1 434 435 except EnvironmentError as ioerror: 436 logger.warning("EnvironmentError: %s" % ioerror) 437 # ignore interrupted io system calls 438 if ioerror.args[0] == 4: # errno 4 is EINTR 439 logger.warning("Skipped EINTR: %s" % ioerror) 440 else: 441 raise 442 except KeyboardInterrupt: 443 if params.observe_only: 444 print("\nKeyboard Interrupt, exiting observer...") 445 main.shutdown = 2 446 if not params.observe_only and main.shutdown == 1: 447 print("\nSecond Keyboard Interrupt, stopping...\n") 448 _, error = server.runCommand(["stateForceShutdown"]) 449 if error: 450 logger.error("Unable to cleanly stop: %s" % error) 451 if not params.observe_only and main.shutdown == 0: 452 print("\nKeyboard Interrupt, closing down...\n") 453 interrupted = True 454 _, error = server.runCommand(["stateShutdown"]) 455 if error: 456 logger.error("Unable to cleanly shutdown: %s" % error) 457 buildinfohelper.cancel_cli_build() 458 main.shutdown = main.shutdown + 1 459 except Exception as e: 460 # print errors to log 461 import traceback 462 from pprint import pformat 463 exception_data = traceback.format_exc() 464 logger.error("%s\n%s" , e, exception_data) 465 466 # save them to database, if possible; if it fails, we already logged to console. 467 try: 468 buildinfohelper.store_log_exception("%s\n%s" % (str(e), exception_data)) 469 except Exception as ce: 470 logger.error("CRITICAL - Failed to to save toaster exception to the database: %s", str(ce)) 471 472 # make sure we return with an error 473 return_value += 1 474 475 if interrupted and return_value == 0: 476 return_value += 1 477 478 logger.warning("Return value is %d", return_value) 479 return return_value 480