event.py, knotty.py, ncurses.py, runningbuild.py: Add support for LogExecTTY event
[bitbake.git] / lib / bb / ui / knotty.py
1 #
2 # BitBake (No)TTY UI Implementation
3 #
4 # Handling output to TTYs or files (no TTY)
5 #
6 # Copyright (C) 2006-2012 Richard Purdie
7 #
8 # This program is free software; you can redistribute it and/or modify
9 # it under the terms of the GNU General Public License version 2 as
10 # published by the Free Software Foundation.
11 #
12 # This program is distributed in the hope that it will be useful,
13 # but WITHOUT ANY WARRANTY; without even the implied warranty of
14 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
15 # GNU General Public License for more details.
16 #
17 # You should have received a copy of the GNU General Public License along
18 # with this program; if not, write to the Free Software Foundation, Inc.,
19 # 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
20
21 from __future__ import division
22
23 import os
24 import sys
25 import xmlrpclib
26 import logging
27 import progressbar
28 import signal
29 import bb.msg
30 import time
31 import fcntl
32 import struct
33 import copy
34 from bb.ui import uihelper
35
36 logger = logging.getLogger("BitBake")
37 interactive = sys.stdout.isatty()
38
39 class BBProgress(progressbar.ProgressBar):
40     def __init__(self, msg, maxval):
41         self.msg = msg
42         widgets = [progressbar.Percentage(), ' ', progressbar.Bar(), ' ',
43            progressbar.ETA()]
44
45         try:
46             self._resize_default = signal.getsignal(signal.SIGWINCH)
47         except:
48             self._resize_default = None
49         progressbar.ProgressBar.__init__(self, maxval, [self.msg + ": "] + widgets)
50
51     def _handle_resize(self, signum, frame):
52         progressbar.ProgressBar._handle_resize(self, signum, frame)
53         if self._resize_default:
54             self._resize_default(signum, frame)
55     def finish(self):
56         progressbar.ProgressBar.finish(self)
57         if self._resize_default:
58             signal.signal(signal.SIGWINCH, self._resize_default)
59
60 class NonInteractiveProgress(object):
61     fobj = sys.stdout
62
63     def __init__(self, msg, maxval):
64         self.msg = msg
65         self.maxval = maxval
66
67     def start(self):
68         self.fobj.write("%s..." % self.msg)
69         self.fobj.flush()
70         return self
71
72     def update(self, value):
73         pass
74
75     def finish(self):
76         self.fobj.write("done.\n")
77         self.fobj.flush()
78
79 def new_progress(msg, maxval):
80     if interactive:
81         return BBProgress(msg, maxval)
82     else:
83         return NonInteractiveProgress(msg, maxval)
84
85 def pluralise(singular, plural, qty):
86     if(qty == 1):
87         return singular % qty
88     else:
89         return plural % qty
90
91
92 class InteractConsoleLogFilter(logging.Filter):
93     def __init__(self, tf, format):
94         self.tf = tf
95         self.format = format
96
97     def filter(self, record):
98         if record.levelno == self.format.NOTE and (record.msg.startswith("Running") or record.msg.startswith("recipe ")):
99             return False
100         self.tf.clearFooter()
101         return True
102
103 class TerminalFilter(object):
104     columns = 80
105
106     def sigwinch_handle(self, signum, frame):
107         self.columns = self.getTerminalColumns()
108         if self._sigwinch_default:
109             self._sigwinch_default(signum, frame)
110
111     def getTerminalColumns(self):
112         def ioctl_GWINSZ(fd):
113             try:
114                 cr = struct.unpack('hh', fcntl.ioctl(fd, self.termios.TIOCGWINSZ, '1234'))
115             except:
116                 return None
117             return cr
118         cr = ioctl_GWINSZ(sys.stdout.fileno())
119         if not cr:
120             try:
121                 fd = os.open(os.ctermid(), os.O_RDONLY)
122                 cr = ioctl_GWINSZ(fd)
123                 os.close(fd)
124             except:
125                 pass
126         if not cr:
127             try:
128                 cr = (env['LINES'], env['COLUMNS'])
129             except:
130                 cr = (25, 80)
131         return cr[1]
132
133     def __init__(self, main, helper, console, format):
134         self.main = main
135         self.helper = helper
136         self.cuu = None
137         self.stdinbackup = None
138         self.interactive = sys.stdout.isatty()
139         self.footer_present = False
140         self.lastpids = []
141
142         if not self.interactive:
143             return
144
145         try:
146             import curses
147         except ImportError:
148             sys.exit("FATAL: The knotty ui could not load the required curses python module.")
149         
150         import termios
151         self.curses = curses
152         self.termios = termios
153         try:
154             fd = sys.stdin.fileno()
155             self.stdinbackup = termios.tcgetattr(fd)
156             new = copy.deepcopy(self.stdinbackup)
157             new[3] = new[3] & ~termios.ECHO
158             termios.tcsetattr(fd, termios.TCSADRAIN, new)
159             curses.setupterm()
160             self.ed = curses.tigetstr("ed")
161             if self.ed:
162                 self.cuu = curses.tigetstr("cuu")
163             try:
164                 self._sigwinch_default = signal.getsignal(signal.SIGWINCH)
165                 signal.signal(signal.SIGWINCH, self.sigwinch_handle)
166             except:
167                 pass
168             self.columns = self.getTerminalColumns()
169         except:
170             self.cuu = None
171         console.addFilter(InteractConsoleLogFilter(self, format))
172
173     def clearFooter(self):
174         if self.footer_present:
175             lines = self.footer_present
176             sys.stdout.write(self.curses.tparm(self.cuu, lines))
177             sys.stdout.write(self.curses.tparm(self.ed))
178         self.footer_present = False
179
180     def updateFooter(self):
181         if not self.cuu:
182             return
183         activetasks = self.helper.running_tasks
184         failedtasks = self.helper.failed_tasks
185         runningpids = self.helper.running_pids
186         if self.footer_present and (self.lastpids == runningpids):
187             return
188         if self.footer_present:
189             self.clearFooter()
190         if not activetasks:
191             return
192         tasks = []
193         for t in runningpids:
194             tasks.append("%s (pid %s)" % (activetasks[t]["title"], t))
195
196         if self.main.shutdown:
197             content = "Waiting for %s running tasks to finish:" % len(activetasks)
198         else:
199             content = "Currently %s running tasks (%s of %s):" % (len(activetasks), self.helper.tasknumber_current, self.helper.tasknumber_total)
200         print content
201         lines = 1 + int(len(content) / (self.columns + 1))
202         for tasknum, task in enumerate(tasks):
203             content = "%s: %s" % (tasknum, task)
204             print content
205             lines = lines + 1 + int(len(content) / (self.columns + 1))
206         self.footer_present = lines
207         self.lastpids = runningpids[:]
208
209     def finish(self):
210         if self.stdinbackup:
211             fd = sys.stdin.fileno()
212             self.termios.tcsetattr(fd, self.termios.TCSADRAIN, self.stdinbackup)
213
214 def main(server, eventHandler, tf = TerminalFilter):
215
216     # Get values of variables which control our output
217     includelogs = server.runCommand(["getVariable", "BBINCLUDELOGS"])
218     loglines = server.runCommand(["getVariable", "BBINCLUDELOGS_LINES"])
219     consolelogfile = server.runCommand(["getVariable", "BB_CONSOLELOG"])
220     if sys.stdin.isatty() and sys.stdout.isatty():
221         log_exec_tty = True
222     else:
223         log_exec_tty = False
224
225     helper = uihelper.BBUIHelper()
226
227     console = logging.StreamHandler(sys.stdout)
228     format = bb.msg.BBLogFormatter("%(levelname)s: %(message)s")
229     bb.msg.addDefaultlogFilter(console)
230     console.setFormatter(format)
231     logger.addHandler(console)
232     if consolelogfile:
233         bb.utils.mkdirhier(os.path.dirname(consolelogfile))
234         consolelog = logging.FileHandler(consolelogfile)
235         bb.msg.addDefaultlogFilter(consolelog)
236         consolelog.setFormatter(format)
237         logger.addHandler(consolelog)
238
239     try:
240         cmdline = server.runCommand(["getCmdLineAction"])
241         if not cmdline:
242             print("Nothing to do.  Use 'bitbake world' to build everything, or run 'bitbake --help' for usage information.")
243             return 1
244         elif not cmdline['action']:
245             print(cmdline['msg'])
246             return 1
247         ret = server.runCommand(cmdline['action'])
248         if ret != True:
249             print("Couldn't get default commandline! %s" % ret)
250             return 1
251     except xmlrpclib.Fault as x:
252         print("XMLRPC Fault getting commandline:\n %s" % x)
253         return 1
254
255     parseprogress = None
256     cacheprogress = None
257     main.shutdown = 0
258     interrupted = False
259     return_value = 0
260     errors = 0
261     warnings = 0
262     taskfailures = []
263
264     termfilter = tf(main, helper, console, format)
265
266     while True:
267         try:
268             termfilter.updateFooter()
269             event = eventHandler.waitEvent(0.25)
270             if event is None:
271                 if main.shutdown > 1:
272                     break
273                 continue
274             helper.eventHandler(event)
275             if isinstance(event, bb.runqueue.runQueueExitWait):
276                 if not main.shutdown:
277                     main.shutdown = 1
278
279             if isinstance(event, bb.event.LogExecTTY):
280                 if log_exec_tty:
281                     tries = event.retries
282                     while tries:
283                         print "Trying to run: %s" % event.prog
284                         if os.system(event.prog) == 0:
285                             break
286                         time.sleep(event.sleep_delay)
287                         tries -= 1
288                     if tries:
289                         continue
290                 logger.warn(event.msg)
291                 continue
292
293             if isinstance(event, logging.LogRecord):
294                 if event.levelno >= format.ERROR:
295                     errors = errors + 1
296                     return_value = 1
297                 elif event.levelno == format.WARNING:
298                     warnings = warnings + 1
299                 # For "normal" logging conditions, don't show note logs from tasks
300                 # but do show them if the user has changed the default log level to 
301                 # include verbose/debug messages
302                 if event.taskpid != 0 and event.levelno <= format.NOTE:
303                     continue
304                 logger.handle(event)
305                 continue
306
307             if isinstance(event, bb.build.TaskFailed):
308                 return_value = 1
309                 logfile = event.logfile
310                 if logfile and os.path.exists(logfile):
311                     termfilter.clearFooter()
312                     print("ERROR: Logfile of failure stored in: %s" % logfile)
313                     if includelogs and not event.errprinted:
314                         print("Log data follows:")
315                         f = open(logfile, "r")
316                         lines = []
317                         while True:
318                             l = f.readline()
319                             if l == '':
320                                 break
321                             l = l.rstrip()
322                             if loglines:
323                                 lines.append(' | %s' % l)
324                                 if len(lines) > int(loglines):
325                                     lines.pop(0)
326                             else:
327                                 print('| %s' % l)
328                         f.close()
329                         if lines:
330                             for line in lines:
331                                 print(line)
332             if isinstance(event, bb.build.TaskBase):
333                 logger.info(event._message)
334                 continue
335             if isinstance(event, bb.event.ParseStarted):
336                 if event.total == 0:
337                     continue
338                 parseprogress = new_progress("Parsing recipes", event.total).start()
339                 continue
340             if isinstance(event, bb.event.ParseProgress):
341                 parseprogress.update(event.current)
342                 continue
343             if isinstance(event, bb.event.ParseCompleted):
344                 if not parseprogress:
345                     continue
346
347                 parseprogress.finish()
348                 print(("Parsing of %d .bb files complete (%d cached, %d parsed). %d targets, %d skipped, %d masked, %d errors."
349                     % ( event.total, event.cached, event.parsed, event.virtuals, event.skipped, event.masked, event.errors)))
350                 continue
351
352             if isinstance(event, bb.event.CacheLoadStarted):
353                 cacheprogress = new_progress("Loading cache", event.total).start()
354                 continue
355             if isinstance(event, bb.event.CacheLoadProgress):
356                 cacheprogress.update(event.current)
357                 continue
358             if isinstance(event, bb.event.CacheLoadCompleted):
359                 cacheprogress.finish()
360                 print("Loaded %d entries from dependency cache." % event.num_entries)
361                 continue
362
363             if isinstance(event, bb.command.CommandFailed):
364                 return_value = event.exitcode
365                 errors = errors + 1
366                 logger.error("Command execution failed: %s", event.error)
367                 main.shutdown = 2
368                 continue
369             if isinstance(event, bb.command.CommandExit):
370                 if not return_value:
371                     return_value = event.exitcode
372                 continue
373             if isinstance(event, (bb.command.CommandCompleted, bb.cooker.CookerExit)):
374                 main.shutdown = 2
375                 continue
376             if isinstance(event, bb.event.MultipleProviders):
377                 logger.info("multiple providers are available for %s%s (%s)", event._is_runtime and "runtime " or "",
378                             event._item,
379                             ", ".join(event._candidates))
380                 logger.info("consider defining a PREFERRED_PROVIDER entry to match %s", event._item)
381                 continue
382             if isinstance(event, bb.event.NoProvider):
383                 return_value = 1
384                 errors = errors + 1
385                 if event._runtime:
386                     r = "R"
387                 else:
388                     r = ""
389
390                 if event._dependees:
391                     logger.error("Nothing %sPROVIDES '%s' (but %s %sDEPENDS on or otherwise requires it)", r, event._item, ", ".join(event._dependees), r)
392                 else:
393                     logger.error("Nothing %sPROVIDES '%s'", r, event._item)
394                 if event._reasons:
395                     for reason in event._reasons:
396                         logger.error("%s", reason)
397                 continue
398
399             if isinstance(event, bb.runqueue.sceneQueueTaskStarted):
400                 logger.info("Running setscene task %d of %d (%s)" % (event.stats.completed + event.stats.active + event.stats.failed + 1, event.stats.total, event.taskstring))
401                 continue
402
403             if isinstance(event, bb.runqueue.runQueueTaskStarted):
404                 if event.noexec:
405                     tasktype = 'noexec task'
406                 else:
407                     tasktype = 'task'
408                 logger.info("Running %s %s of %s (ID: %s, %s)",
409                             tasktype,
410                             event.stats.completed + event.stats.active +
411                                 event.stats.failed + 1,
412                             event.stats.total, event.taskid, event.taskstring)
413                 continue
414
415             if isinstance(event, bb.runqueue.runQueueTaskFailed):
416                 taskfailures.append(event.taskstring)
417                 logger.error("Task %s (%s) failed with exit code '%s'",
418                              event.taskid, event.taskstring, event.exitcode)
419                 continue
420
421             if isinstance(event, bb.runqueue.sceneQueueTaskFailed):
422                 logger.warn("Setscene task %s (%s) failed with exit code '%s' - real task will be run instead",
423                              event.taskid, event.taskstring, event.exitcode)
424                 continue
425
426             # ignore
427             if isinstance(event, (bb.event.BuildBase,
428                                   bb.event.StampUpdate,
429                                   bb.event.ConfigParsed,
430                                   bb.event.RecipeParsed,
431                                   bb.event.RecipePreFinalise,
432                                   bb.runqueue.runQueueEvent,
433                                   bb.runqueue.runQueueExitWait,
434                                   bb.event.OperationStarted,
435                                   bb.event.OperationCompleted,
436                                   bb.event.OperationProgress)):
437                 continue
438
439             logger.error("Unknown event: %s", event)
440
441         except EnvironmentError as ioerror:
442             termfilter.clearFooter()
443             # ignore interrupted io
444             if ioerror.args[0] == 4:
445                 pass
446         except KeyboardInterrupt:
447             termfilter.clearFooter()
448             if main.shutdown == 1:
449                 print("\nSecond Keyboard Interrupt, stopping...\n")
450                 server.runCommand(["stateStop"])
451             if main.shutdown == 0:
452                 interrupted = True
453                 print("\nKeyboard Interrupt, closing down...\n")
454                 server.runCommand(["stateShutdown"])
455             main.shutdown = main.shutdown + 1
456             pass
457
458     summary = ""
459     if taskfailures:
460         summary += pluralise("\nSummary: %s task failed:",
461                              "\nSummary: %s tasks failed:", len(taskfailures))
462         for failure in taskfailures:
463             summary += "\n  %s" % failure
464     if warnings:
465         summary += pluralise("\nSummary: There was %s WARNING message shown.",
466                              "\nSummary: There were %s WARNING messages shown.", warnings)
467     if return_value:
468         summary += pluralise("\nSummary: There was %s ERROR message shown, returning a non-zero exit code.",
469                              "\nSummary: There were %s ERROR messages shown, returning a non-zero exit code.", errors)
470     if summary:
471         print(summary)
472
473     if interrupted:
474         print("Execution was interrupted, returning a non-zero exit code.")
475         if return_value == 0:
476             return_value = 1
477
478     termfilter.finish()
479
480     return return_value