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 # TODO don't use log output to determine when bitbake has started 135 # 136 # WARNING: this log handler cannot be removed, as localhostbecontroller 137 # relies on output in the toaster_ui.log file to determine whether 138 # the bitbake server has started, which only happens if 139 # this logger is setup here (see the TODO in the loop below) 140 console = logging.StreamHandler(sys.stdout) 141 format_str = "%(levelname)s: %(message)s" 142 formatter = bb.msg.BBLogFormatter(format_str) 143 bb.msg.addDefaultlogFilter(console) 144 console.setFormatter(formatter) 145 logger.addHandler(console) 146 logger.setLevel(logging.INFO) 147 llevel, debug_domains = bb.msg.constructLogOptions() 148 result, error = server.runCommand(["setEventMask", server.getEventHandle(), llevel, debug_domains, _evt_list]) 149 if not result or error: 150 logger.error("can't set event mask: %s", error) 151 return 1 152 153 # verify and warn 154 build_history_enabled = True 155 inheritlist, _ = server.runCommand(["getVariable", "INHERIT"]) 156 157 if not "buildhistory" in inheritlist.split(" "): 158 logger.warning("buildhistory is not enabled. Please enable INHERIT += \"buildhistory\" to see image details.") 159 build_history_enabled = False 160 161 if not "buildstats" in inheritlist.split(" "): 162 logger.warning("buildstats is not enabled. Please enable INHERIT += \"buildstats\" to generate build statistics.") 163 164 if not params.observe_only: 165 params.updateFromServer(server) 166 params.updateToServer(server, os.environ.copy()) 167 cmdline = params.parseActions() 168 if not cmdline: 169 print("Nothing to do. Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.") 170 return 1 171 if 'msg' in cmdline and cmdline['msg']: 172 logger.error(cmdline['msg']) 173 return 1 174 175 ret, error = server.runCommand(cmdline['action']) 176 if error: 177 logger.error("Command '%s' failed: %s" % (cmdline, error)) 178 return 1 179 elif ret != True: 180 logger.error("Command '%s' failed: returned %s" % (cmdline, ret)) 181 return 1 182 183 # set to 1 when toasterui needs to shut down 184 main.shutdown = 0 185 186 interrupted = False 187 return_value = 0 188 errors = 0 189 warnings = 0 190 taskfailures = [] 191 first = True 192 193 buildinfohelper = BuildInfoHelper(server, build_history_enabled, 194 os.getenv('TOASTER_BRBE')) 195 196 # write our own log files into bitbake's log directory; 197 # we're only interested in the path to the parent directory of 198 # this file, as we're writing our own logs into the same directory 199 consolelogfile = _log_settings_from_server(server) 200 log_dir = os.path.dirname(consolelogfile) 201 bb.utils.mkdirhier(log_dir) 202 203 while True: 204 try: 205 event = eventHandler.waitEvent(0.25) 206 if first: 207 first = False 208 209 # TODO don't use log output to determine when bitbake has started 210 # 211 # this is the line localhostbecontroller needs to 212 # see in toaster_ui.log which it uses to decide whether 213 # the bitbake server has started... 214 logger.info("ToasterUI waiting for events") 215 216 if event is None: 217 if main.shutdown > 0: 218 # if shutting down, close any open build log first 219 _close_build_log(build_log) 220 221 break 222 continue 223 224 helper.eventHandler(event) 225 226 # pylint: disable=protected-access 227 # the code will look into the protected variables of the event; no easy way around this 228 229 if isinstance(event, bb.event.HeartbeatEvent): 230 continue 231 232 if isinstance(event, bb.event.ParseStarted): 233 if not (build_log and build_log_file_path): 234 build_log, build_log_file_path = _open_build_log(log_dir) 235 236 buildinfohelper.store_started_build() 237 buildinfohelper.save_build_log_file_path(build_log_file_path) 238 buildinfohelper.set_recipes_to_parse(event.total) 239 continue 240 241 # create a build object in buildinfohelper from either BuildInit 242 # (if available) or BuildStarted (for jethro and previous versions) 243 if isinstance(event, (bb.event.BuildStarted, bb.event.BuildInit)): 244 if not (build_log and build_log_file_path): 245 build_log, build_log_file_path = _open_build_log(log_dir) 246 247 buildinfohelper.save_build_targets(event) 248 buildinfohelper.save_build_log_file_path(build_log_file_path) 249 250 # get additional data from BuildStarted 251 if isinstance(event, bb.event.BuildStarted): 252 buildinfohelper.save_build_layers_and_variables() 253 continue 254 255 if isinstance(event, bb.event.ParseProgress): 256 buildinfohelper.set_recipes_parsed(event.current) 257 continue 258 259 if isinstance(event, bb.event.ParseCompleted): 260 buildinfohelper.set_recipes_parsed(event.total) 261 continue 262 263 if isinstance(event, (bb.build.TaskStarted, bb.build.TaskSucceeded, bb.build.TaskFailedSilent)): 264 buildinfohelper.update_and_store_task(event) 265 logger.info("Logfile for task %s", event.logfile) 266 continue 267 268 if isinstance(event, bb.build.TaskBase): 269 logger.info(event._message) 270 271 if isinstance(event, bb.event.LogExecTTY): 272 logger.info(event.msg) 273 continue 274 275 if isinstance(event, logging.LogRecord): 276 if event.levelno == -1: 277 event.levelno = formatter.ERROR 278 279 buildinfohelper.store_log_event(event) 280 281 if event.levelno >= formatter.ERROR: 282 errors = errors + 1 283 elif event.levelno == formatter.WARNING: 284 warnings = warnings + 1 285 286 # For "normal" logging conditions, don't show note logs from tasks 287 # but do show them if the user has changed the default log level to 288 # include verbose/debug messages 289 if event.taskpid != 0 and event.levelno <= formatter.NOTE: 290 continue 291 292 logger.handle(event) 293 continue 294 295 if isinstance(event, bb.build.TaskFailed): 296 buildinfohelper.update_and_store_task(event) 297 logfile = event.logfile 298 if logfile and os.path.exists(logfile): 299 bb.error("Logfile of failure stored in: %s" % logfile) 300 continue 301 302 # these events are unprocessed now, but may be used in the future to log 303 # timing and error informations from the parsing phase in Toaster 304 if isinstance(event, (bb.event.SanityCheckPassed, bb.event.SanityCheck)): 305 continue 306 if isinstance(event, bb.event.CacheLoadStarted): 307 continue 308 if isinstance(event, bb.event.CacheLoadProgress): 309 continue 310 if isinstance(event, bb.event.CacheLoadCompleted): 311 continue 312 if isinstance(event, bb.event.MultipleProviders): 313 logger.info(str(event)) 314 continue 315 316 if isinstance(event, bb.event.NoProvider): 317 errors = errors + 1 318 text = str(event) 319 logger.error(text) 320 buildinfohelper.store_log_error(text) 321 continue 322 323 if isinstance(event, bb.event.ConfigParsed): 324 continue 325 if isinstance(event, bb.event.RecipeParsed): 326 continue 327 328 # end of saved events 329 330 if isinstance(event, (bb.runqueue.sceneQueueTaskStarted, bb.runqueue.runQueueTaskStarted, bb.runqueue.runQueueTaskSkipped)): 331 buildinfohelper.store_started_task(event) 332 continue 333 334 if isinstance(event, bb.runqueue.runQueueTaskCompleted): 335 buildinfohelper.update_and_store_task(event) 336 continue 337 338 if isinstance(event, bb.runqueue.runQueueTaskFailed): 339 buildinfohelper.update_and_store_task(event) 340 taskfailures.append(event.taskstring) 341 logger.error(str(event)) 342 continue 343 344 if isinstance(event, (bb.runqueue.sceneQueueTaskCompleted, bb.runqueue.sceneQueueTaskFailed)): 345 buildinfohelper.update_and_store_task(event) 346 continue 347 348 349 if isinstance(event, (bb.event.TreeDataPreparationStarted, bb.event.TreeDataPreparationCompleted)): 350 continue 351 352 if isinstance(event, (bb.event.BuildCompleted, bb.command.CommandFailed)): 353 354 errorcode = 0 355 if isinstance(event, bb.command.CommandFailed): 356 errors += 1 357 errorcode = 1 358 logger.error(str(event)) 359 elif isinstance(event, bb.event.BuildCompleted): 360 buildinfohelper.scan_image_artifacts() 361 buildinfohelper.clone_required_sdk_artifacts() 362 363 # turn off logging to the current build log 364 _close_build_log(build_log) 365 366 # reset ready for next BuildStarted 367 build_log = None 368 369 # update the build info helper on BuildCompleted, not on CommandXXX 370 buildinfohelper.update_build_information(event, errors, warnings, taskfailures) 371 372 brbe = buildinfohelper.brbe 373 buildinfohelper.close(errorcode) 374 375 # we start a new build info 376 if params.observe_only: 377 logger.debug("ToasterUI prepared for new build") 378 errors = 0 379 warnings = 0 380 taskfailures = [] 381 buildinfohelper = BuildInfoHelper(server, build_history_enabled) 382 else: 383 main.shutdown = 1 384 385 logger.info("ToasterUI build done, brbe: %s", brbe) 386 continue 387 388 if isinstance(event, (bb.command.CommandCompleted, 389 bb.command.CommandFailed, 390 bb.command.CommandExit)): 391 if params.observe_only: 392 errorcode = 0 393 else: 394 main.shutdown = 1 395 396 continue 397 398 if isinstance(event, bb.event.MetadataEvent): 399 if event.type == "SinglePackageInfo": 400 buildinfohelper.store_build_package_information(event) 401 elif event.type == "LayerInfo": 402 buildinfohelper.store_layer_info(event) 403 elif event.type == "BuildStatsList": 404 buildinfohelper.store_tasks_stats(event) 405 elif event.type == "ImagePkgList": 406 buildinfohelper.store_target_package_data(event) 407 elif event.type == "MissedSstate": 408 buildinfohelper.store_missed_state_tasks(event) 409 elif event.type == "SDKArtifactInfo": 410 buildinfohelper.scan_sdk_artifacts(event) 411 elif event.type == "SetBRBE": 412 buildinfohelper.brbe = buildinfohelper._get_data_from_event(event) 413 elif event.type == "TaskArtifacts": 414 buildinfohelper.scan_task_artifacts(event) 415 elif event.type == "OSErrorException": 416 logger.error(event) 417 else: 418 logger.error("Unprocessed MetadataEvent %s", event.type) 419 continue 420 421 if isinstance(event, bb.cooker.CookerExit): 422 # shutdown when bitbake server shuts down 423 main.shutdown = 1 424 continue 425 426 if isinstance(event, bb.event.DepTreeGenerated): 427 buildinfohelper.store_dependency_information(event) 428 continue 429 430 logger.warning("Unknown event: %s", event) 431 return_value += 1 432 433 except EnvironmentError as ioerror: 434 logger.warning("EnvironmentError: %s" % ioerror) 435 # ignore interrupted io system calls 436 if ioerror.args[0] == 4: # errno 4 is EINTR 437 logger.warning("Skipped EINTR: %s" % ioerror) 438 else: 439 raise 440 except KeyboardInterrupt: 441 if params.observe_only: 442 print("\nKeyboard Interrupt, exiting observer...") 443 main.shutdown = 2 444 if not params.observe_only and main.shutdown == 1: 445 print("\nSecond Keyboard Interrupt, stopping...\n") 446 _, error = server.runCommand(["stateForceShutdown"]) 447 if error: 448 logger.error("Unable to cleanly stop: %s" % error) 449 if not params.observe_only and main.shutdown == 0: 450 print("\nKeyboard Interrupt, closing down...\n") 451 interrupted = True 452 _, error = server.runCommand(["stateShutdown"]) 453 if error: 454 logger.error("Unable to cleanly shutdown: %s" % error) 455 buildinfohelper.cancel_cli_build() 456 main.shutdown = main.shutdown + 1 457 except Exception as e: 458 # print errors to log 459 import traceback 460 from pprint import pformat 461 exception_data = traceback.format_exc() 462 logger.error("%s\n%s" , e, exception_data) 463 464 # save them to database, if possible; if it fails, we already logged to console. 465 try: 466 buildinfohelper.store_log_exception("%s\n%s" % (str(e), exception_data)) 467 except Exception as ce: 468 logger.error("CRITICAL - Failed to to save toaster exception to the database: %s", str(ce)) 469 470 # make sure we return with an error 471 return_value += 1 472 473 if interrupted and return_value == 0: 474 return_value += 1 475 476 logger.warning("Return value is %d", return_value) 477 return return_value 478