toasterui.py 19 KB

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