toasterui.py 18 KB

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