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