# HG changeset patch
# User cmlenz
# Date 1120679050 0
# Node ID dc1c7fc9b915067dbb577946f8338e94d97af70b
# Parent  87098cbcdc90a20600d3b8acb10d84472b8709b8
Record the output of build steps in the database. See #12. Still need to get better granularity in transmitting the log output from slave to master before #12 can be closed.

diff --git a/bitten/build/ctools.py b/bitten/build/ctools.py
--- a/bitten/build/ctools.py
+++ b/bitten/build/ctools.py
@@ -33,11 +33,7 @@
     args.append(target)
     cmdline = Commandline('make', args)
     for out, err in cmdline.execute(timeout=100.0):
-        if out:
-            for line in out.splitlines():
-                print '[make] %s' % line
-        if err:
-            for line in err.splitlines():
-                print '[make] %s' % err
+        ctxt.log(ctxt.OUTPUT, out)
+        ctxt.log(ctxt.ERROR, err)
     if cmdline.returncode != 0:
         raise BuildError, "Executing make failed (%s)" % cmdline.returncode
diff --git a/bitten/build/pythontools.py b/bitten/build/pythontools.py
--- a/bitten/build/pythontools.py
+++ b/bitten/build/pythontools.py
@@ -27,10 +27,8 @@
     """Execute a `distutils` command."""
     cmdline = Commandline('python', ['setup.py', command], cwd=ctxt.basedir)
     for out, err in cmdline.execute(timeout=100.0):
-        if out:
-            print '[distutils] %s' % out
-        if err:
-            print '[distutils] %s' % err
+        ctxt.log(ctxt.OUTPUT, out)
+        ctxt.log(ctxt.ERROR, err)
     if cmdline.returncode != 0:
         raise BuildError, 'Executing distutils failed (%s)' % cmdline.returncode
 
diff --git a/bitten/master.py b/bitten/master.py
--- a/bitten/master.py
+++ b/bitten/master.py
@@ -24,7 +24,7 @@
 import time
 
 from trac.env import Environment
-from bitten.model import Build, BuildConfig, TargetPlatform
+from bitten.model import BuildConfig, TargetPlatform, Build, BuildStep
 from bitten.util import archive, beep, xmlio
 
 
@@ -235,11 +235,11 @@
                 if elem.name == 'error':
                     logging.warning('Slave did not accept archive: %s (%d)',
                                     elem.gettext(), int(elem.attr['code']))
+
             if cmd == 'ANS':
                 elem = xmlio.parse(msg.get_payload())
-                logging.debug('Received build answer <%s>' % elem.name)
+
                 if elem.name == 'started':
-                    self.steps = []
                     build.slave = self.name
                     build.slave_info.update(self.props)
                     build.started = int(time.time())
@@ -247,20 +247,33 @@
                     build.update()
                     logging.info('Slave %s started build of "%s" as of [%s]',
                                  self.name, build.config, build.rev)
+
                 elif elem.name == 'step':
-                    logging.info('Slave completed step "%s"',
-                                 elem.attr['id'])
+                    logging.info('Slave completed step "%s"', elem.attr['id'])
+                    step = BuildStep(self.env)
+                    step.build = build.id
+                    step.name = elem.attr['id']
+                    step.description = elem.attr.get('description')
+                    step.stopped = int(time.time())
+                    step.log = elem.gettext().strip()
                     if elem.attr['result'] == 'failure':
                         logging.warning('Step failed: %s', elem.gettext())
-                    self.steps.append((elem.attr['id'],
-                                       elem.attr['result']))
+                        step.status = BuildStep.FAILURE
+                    else:
+                        step.status = BuildStep.SUCCESS
+                    step.insert()
+
                 elif elem.name == 'aborted':
                     logging.info('Slave "%s" aborted build', self.name)
                     build.slave = None
                     build.started = 0
                     build.status = Build.PENDING
+
                 elif elem.name == 'error':
                     build.status = Build.FAILURE
+
+                build.update()
+
             elif cmd == 'NUL':
                 if build.status != Build.PENDING: # Completed
                     logging.info('Slave %s completed build of "%s" as of [%s]',
@@ -268,13 +281,16 @@
                     build.stopped = int(time.time())
                     if build.status is Build.IN_PROGRESS:
                         # Find out whether the build failed or succeeded
-                        if [st for st in self.steps if st[1] == 'failure']:
-                            build.status = Build.FAILURE
-                        else:
-                            build.status = Build.SUCCESS
+                        build.status = Build.SUCCESS
+                        for step in BuildStep.select(self.env, build=build.id):
+                            if step.status == BuildStep.FAILURE:
+                                build.status = Build.FAILURE
+                                break
+
                 else: # Aborted
                     build.slave = None
                     build.started = 0
+
                 build.update()
 
         # TODO: should not block while reading the file; rather stream it using
diff --git a/bitten/model.py b/bitten/model.py
--- a/bitten/model.py
+++ b/bitten/model.py
@@ -244,7 +244,7 @@
             Column('id', auto_increment=True), Column('config'), Column('rev'),
             Column('rev_time', type='int'), Column('platform', type='int'),
             Column('slave'), Column('started', type='int'),
-            Column('stopped', type='int'), Column('status', size='1'),
+            Column('stopped', type='int'), Column('status', size=1),
             Index(['config', 'rev', 'slave'])
         ],
         Table('bitten_slave', key=('build', 'propname'))[
@@ -415,5 +415,101 @@
     select = classmethod(select)
 
 
-schema = BuildConfig._schema + TargetPlatform._schema + Build._schema
+class BuildStep(object):
+    """Represents an individual step of an executed build."""
+
+    _schema = [
+        Table('bitten_step', key=('build', 'name'))[
+            Column('build', type='int'), Column('name'), Column('description'),
+            Column('status', size=1), Column('log'),
+            Column('started', type='int'), Column('stopped', type='int')
+        ]
+    ]
+
+    # Step status codes
+    SUCCESS = 'S'
+    FAILURE = 'F'
+
+    def __init__(self, env, build=None, name=None, db=None):
+        self.env = env
+        if build is not None and name is not None:
+            self._fetch(build, name, db)
+        else:
+            self.build = self.name = self.description = self.status = None
+            self.log = self.started = self.stopped = None
+
+    def _fetch(self, build, name, db=None):
+        if not db:
+            db = self.env.get_db_cnx()
+
+        cursor = db.cursor()
+        cursor.execute("SELECT description,status,log,started,stopped "
+                       "FROM bitten_step WHERE build=%s AND name=%s",
+                       (build, name))
+        row = cursor.fetchone()
+        if not row:
+            raise Exception, "Build step %s of %s not found" % (name, build)
+        self.build = build
+        self.name = name
+        self.description = row[0] or ''
+        self.status = row[1]
+        self.log = row[2] or ''
+        self.started = row[3] and int(row[3]) or 0
+        self.stopped = row[4] and int(row[4]) or 0
+
+    exists = property(fget=lambda self: self.build is not None)
+    successful = property(fget=lambda self: self.status == BuildStep.SUCCESS)
+
+    def insert(self, db=None):
+        if not db:
+            db = self.env.get_db_cnx()
+            handle_ta = True
+        else:
+            handle_ta = False
+
+        assert self.build and self.name
+        assert self.status in (self.SUCCESS, self.FAILURE)
+
+        cursor = db.cursor()
+        cursor.execute("INSERT INTO bitten_step (build,name,description,status,"
+                       "log,started,stopped) VALUES (%s,%s,%s,%s,%s,%s,%s)",
+                       (self.build, self.name, self.description or '',
+                        self.status, self.log or '', self.started or 0,
+                        self.stopped or 0))
+        if handle_ta:
+            db.commit()
+
+    def select(cls, env, build=None, name=None, db=None):
+        if not db:
+            db = env.get_db_cnx()
+
+        where_clauses = []
+        if build is not None:
+            where_clauses.append(("build=%s", build))
+        if name is not None:
+            where_clauses.append(("name=%s", name))
+        if where_clauses:
+            where = "WHERE " + " AND ".join([wc[0] for wc in where_clauses])
+        else:
+            where = ""
+
+        cursor = db.cursor()
+        cursor.execute("SELECT build,name,description,status,log,started,"
+                       "stopped FROM bitten_step %s ORDER BY stopped"
+                       % where, [wc[1] for wc in where_clauses])
+        for build, name, description, status, log, started, stopped in cursor:
+            step = BuildStep(env)
+            step.build = build
+            step.name = name
+            step.description = description
+            step.status = status
+            step.log = log
+            step.started = started and int(started) or 0
+            step.stopped = stopped and int(stopped) or 0
+            yield step
+    select = classmethod(select)
+
+
+schema = BuildConfig._schema + TargetPlatform._schema + Build._schema + \
+         BuildStep._schema
 schema_version = 1
diff --git a/bitten/recipe.py b/bitten/recipe.py
--- a/bitten/recipe.py
+++ b/bitten/recipe.py
@@ -20,6 +20,7 @@
 
 import logging
 import os.path
+import time
 
 from bitten.build import BuildError
 from bitten.util import xmlio
@@ -34,8 +35,27 @@
 class Context(object):
     """The context in which a recipe command or report is run."""
 
+    ERROR = 0
+    OUTPUT = 1
+
+    current_step = None
+    current_function = None
+
     def __init__(self, basedir):
         self.basedir = basedir
+        self._log = []
+
+    def log(self, level, text):
+        if text is None:
+            return
+        assert level in (Context.ERROR, Context.OUTPUT), \
+               'Invalid log level %s' % level
+        if level == Context.ERROR:
+            logging.warning(text)
+        else:
+            logging.info(text)
+        self._log.append((self.current_step, self.current_function, level,
+                          time.time(), text))
 
     def resolve(self, *path):
         return os.path.normpath(os.path.join(self.basedir, *path))
@@ -65,14 +85,20 @@
                 raise InvalidRecipeError, "Unknown element <%s>" % child.name
 
     def execute(self, ctxt):
+        ctxt.current_step = self
         try:
-            for function, args in self:
-                function(ctxt, **args)
-        except BuildError, e:
-            if self.onerror == 'fail':
-                raise BuildError, e
-            logging.warning('Ignoring error in step %s (%s)', self.id, e)
-            return None
+            try:
+                for function, args in self:
+                    ctxt.current_function = function.__name__
+                    function(ctxt, **args)
+                    ctxt.current_function = None
+            except BuildError, e:
+                if self.onerror == 'fail':
+                    raise BuildError, e
+                logging.warning('Ignoring error in step %s (%s)', self.id, e)
+                return None
+        finally:
+            ctxt.current_step = None
 
     def _args(self, elem):
         return dict([(name.replace('-', '_'), value) for name, value
diff --git a/bitten/slave.py b/bitten/slave.py
--- a/bitten/slave.py
+++ b/bitten/slave.py
@@ -142,7 +142,10 @@
                 try:
                     step.execute(recipe.ctxt)
                     xml = xmlio.Element('step', id=step.id, result='success',
-                                        description=step.description)
+                                        description=step.description)[
+                        '\n'.join([record[-1] for record in recipe.ctxt._log])
+                    ]
+                    recipe.ctxt._log = []
                     self.channel.send_ans(msgno, beep.MIMEMessage(xml))
                 except (BuildError, InvalidRecipeError), e:
                     xml = xmlio.Element('step', id=step.id, result='failure',
diff --git a/bitten/tests/model.py b/bitten/tests/model.py
--- a/bitten/tests/model.py
+++ b/bitten/tests/model.py
@@ -21,7 +21,7 @@
 import unittest
 
 from trac.test import EnvironmentStub
-from bitten.model import Build, BuildConfig, TargetPlatform
+from bitten.model import BuildConfig, TargetPlatform, Build, BuildStep
 
 
 class BuildConfigTestCase(unittest.TestCase):
@@ -225,11 +225,66 @@
         self.assertEquals('joe@example.org', build.slave_info[Build.MAINTAINER])
 
 
+class BuildStepTestCase(unittest.TestCase):
+
+    def setUp(self):
+        self.env = EnvironmentStub()
+        db = self.env.get_db_cnx()
+        cursor = db.cursor()
+        for table in BuildStep._schema:
+            cursor.execute(db.to_sql(table))
+        db.commit()
+
+    def test_new(self):
+        step = BuildStep(self.env)
+        self.assertEqual(None, step.build)
+        self.assertEqual(None, step.name)
+
+    def test_insert(self):
+        step = BuildStep(self.env)
+        step.build = 1
+        step.name = 'test'
+        step.description = 'Foo bar'
+        step.status = BuildStep.SUCCESS
+        step.insert()
+
+        db = self.env.get_db_cnx()
+        cursor = db.cursor()
+        cursor.execute("SELECT build,name,description,status,log,started"
+                       ",stopped FROM bitten_step")
+        self.assertEqual((1, 'test', 'Foo bar', BuildStep.SUCCESS, '', 0, 0),
+                         cursor.fetchone())
+
+    def test_insert_no_build_or_name(self):
+        # No build
+        step = BuildStep(self.env)
+        step.name = 'test'
+        self.assertRaises(AssertionError, step.insert)
+
+        # No name
+        step = BuildStep(self.env)
+        step.build = 1
+        self.assertRaises(AssertionError, step.insert)
+
+    def test_fetch(self):
+        db = self.env.get_db_cnx()
+        cursor = db.cursor()
+        cursor.execute("INSERT INTO bitten_step VALUES (%s,%s,%s,%s,%s,%s,%s)",
+                       (1, 'test', 'Foo bar', BuildStep.SUCCESS, '', 0, 0))
+
+        step = BuildStep(self.env, 1, 'test')
+        self.assertEqual(1, step.build)
+        self.assertEqual('test', step.name)
+        self.assertEqual('Foo bar', step.description)
+        self.assertEqual(BuildStep.SUCCESS, step.status)
+
+
 def suite():
     suite = unittest.TestSuite()
     suite.addTest(unittest.makeSuite(BuildConfigTestCase, 'test'))
     suite.addTest(unittest.makeSuite(TargetPlatformTestCase, 'test'))
     suite.addTest(unittest.makeSuite(BuildTestCase, 'test'))
+    suite.addTest(unittest.makeSuite(BuildStepTestCase, 'test'))
     return suite
 
 if __name__ == '__main__':
diff --git a/bitten/trac_ext/web_ui.py b/bitten/trac_ext/web_ui.py
--- a/bitten/trac_ext/web_ui.py
+++ b/bitten/trac_ext/web_ui.py
@@ -29,7 +29,7 @@
                             add_link, add_stylesheet
 from trac.web.main import IRequestHandler
 from trac.wiki import wiki_to_html
-from bitten.model import Build, BuildConfig, TargetPlatform
+from bitten.model import BuildConfig, TargetPlatform, Build, BuildStep
 
 def _find_dir(name):
     import bitten
@@ -376,7 +376,7 @@
         req.hdf['build.platform'] = {
             'name': platform.name, 'id': platform.id, 'exists': platform.exists,
             'rules': [{'property': propname, 'pattern': pattern}
-                      for propname, pattern in platform.rules] + [('', '')]
+                      for propname, pattern in platform.rules] or [('', '')]
         }
         req.hdf['build.mode'] = 'edit_platform'
 
@@ -419,4 +419,12 @@
             'machine': build.slave_info.get(Build.MACHINE),
             'processor': build.slave_info.get(Build.PROCESSOR)
         }
+        steps = []
+        for step in BuildStep.select(self.env, build=build.id):
+            steps.append({
+                'name': step.name, 'description': step.description,
+                'log': step.log
+            })
+        hdf['steps'] = steps
+
         return hdf
diff --git a/bitten/util/beep.py b/bitten/util/beep.py
--- a/bitten/util/beep.py
+++ b/bitten/util/beep.py
@@ -40,7 +40,8 @@
 
 from bitten.util import xmlio
 
-__all__ = ['Listener', 'Initiator', 'Profile']
+__all__ = ['Listener', 'Initiator', 'MIMEMessage', 'ProfileHandler',
+           'ProtocolError']
 
 BEEP_XML = 'application/beep+xml'
 
diff --git a/htdocs/build.css b/htdocs/build.css
--- a/htdocs/build.css
+++ b/htdocs/build.css
@@ -15,3 +15,5 @@
 #content.build #builds td.completed { background: #9d9; }
 #content.build #builds td.failed { background: #d99; }
 #content.build #builds td.in-progress { background: #ff9; }
+
+#content.build pre.log { overflow: auto; white-space: pre; }
diff --git a/templates/build.cs b/templates/build.cs
--- a/templates/build.cs
+++ b/templates/build.cs
@@ -156,6 +156,11 @@
      /if ?>)</p>
    <p class="time">Completed: <?cs var:build.started ?> (<?cs
      var:build.started_delta ?> ago)<br />Took: <?cs var:build.duration ?></p><?cs
+  each:step = build.steps ?>
+   <h2><?cs var:step.name ?></h2>
+   <p><?cs var:step.description ?></p>
+   <pre class="log"><?cs var:step.log ?></pre><?cs
+  /each ?><?cs
   /if ?>
 
  </div>