changeset 109:5bf22bb87915

Transmit build log and generated data back to the build master in XML format. Closes #23.
author cmlenz
date Wed, 03 Aug 2005 11:54:34 +0000
parents 2a720491d903
children c58c74e7df16
files bitten/build/ctools.py bitten/build/pythontools.py bitten/master.py bitten/recipe.py bitten/slave.py bitten/util/xmlio.py recipe.xml scripts/build.py
diffstat 8 files changed, 147 insertions(+), 97 deletions(-) [+]
line wrap: on
line diff
--- a/bitten/build/ctools.py
+++ b/bitten/build/ctools.py
@@ -18,22 +18,35 @@
 #
 # Author: Christopher Lenz <cmlenz@gmx.de>
 
+import logging
+
 from bitten.build import BuildError
+from bitten.util import xmlio
 from bitten.util.cmdline import Commandline
 
-def make(ctxt, target='all', file=None, jobs=None, keep_going=False):
+log = logging.getLogger('bitten.build.ctools')
+
+def make(ctxt, target=None, file=None, jobs=None, keep_going=False):
     """Execute a Makefile target."""
-    args = ['-C', ctxt.basedir]
+    args = ['--directory', ctxt.basedir]
     if file:
-        args += ['-f', ctxt.resolve(file)]
+        args += ['--file', ctxt.resolve(file)]
     if jobs:
-        args += ['-j', int(jobs)]
+        args += ['--jobs', int(jobs)]
     if keep_going:
-        args.append('-k')
-    args.append(target)
+        args.append('--keep-going')
+    if target:
+        args.append(target)
+
+    log_elem = xmlio.Element('messages')
     cmdline = Commandline('make', args)
     for out, err in cmdline.execute(timeout=100.0):
-        ctxt.log(ctxt.OUTPUT, out)
-        ctxt.log(ctxt.ERROR, err)
+        if out:
+            log.info(out)
+            xmlio.SubElement(log_elem, 'message', level='info')[out]
+        if err:
+            log.error(err)
+            xmlio.SubElement(log_elem, 'message', level='error')[err]
+    ctxt.log(log_elem)
     if cmdline.returncode != 0:
         raise BuildError, 'make failed (%s)' % cmdline.returncode
--- a/bitten/build/pythontools.py
+++ b/bitten/build/pythontools.py
@@ -18,38 +18,62 @@
 #
 # Author: Christopher Lenz <cmlenz@gmx.de>
 
+import logging
 import re
 
 from bitten.build import BuildError
+from bitten.util import xmlio
 from bitten.util.cmdline import Commandline
 
+log = logging.getLogger('bitten.build.pythontools')
+
 def distutils(ctxt, command='build'):
     """Execute a `distutils` command."""
     cmdline = Commandline('python', ['setup.py', command], cwd=ctxt.basedir)
+    log_elem = xmlio.Element('messages')
     for out, err in cmdline.execute(timeout=100.0):
-        ctxt.log(ctxt.OUTPUT, out)
-        ctxt.log(ctxt.ERROR, err)
+        if out:
+            log.info(out)
+            xmlio.SubElement(log_elem, 'message', level='info')[out]
+        if err:
+            level = 'error'
+            if err.startswith('warning: '):
+                err = err[9:]
+                level = 'warning'
+                log.warning(err)
+            else:
+                log.error(err)
+            xmlio.SubElement(log_elem, 'message', level=level)[err]
+    ctxt.log(log_elem)
     if cmdline.returncode != 0:
         raise BuildError, 'distutils failed (%s)' % cmdline.returncode
 
 def pylint(ctxt, file=None):
     """Extract data from a `pylint` run written to a file."""
     assert file, 'Missing required attribute "file"'
-    _msg_re = re.compile(r'^(?P<file>.+):(?P<line>\d+): '
+    msg_re = re.compile(r'^(?P<file>.+):(?P<line>\d+): '
                          r'\[(?P<type>[A-Z])(?:, (?P<tag>[\w\.]+))?\] '
                          r'(?P<msg>.*)$')
+    msg_types = dict(W='warning', E='error', C='convention', R='refactor')
 
+    lint_elem = xmlio.Element('lint')
     try:
         fd = open(ctxt.resolve(file), 'r')
         try:
             for line in fd:
-                match = _msg_re.search(line)
+                match = msg_re.search(line)
                 if match:
+                    type = msg_types.get(match.group('type'))
                     filename = match.group('file')
                     if filename.startswith(ctxt.basedir):
                         filename = filename[len(ctxt.basedir) + 1:]
                     lineno = int(match.group('line'))
-                    # TODO: emit to build master
+                    tag = match.group('tag')
+                    xmlio.SubElement(lint_elem, 'problem', type=type, tag=tag,
+                                     file=filename, line=lineno)[
+                        match.group('msg') or ''
+                    ]
+            ctxt.report(lint_elem)
         finally:
             fd.close()
     except IOError, e:
--- a/bitten/master.py
+++ b/bitten/master.py
@@ -31,6 +31,7 @@
 
 from trac.env import Environment
 from bitten.model import BuildConfig, TargetPlatform, Build, BuildStep
+from bitten.store import MetricsStore
 from bitten.util import archive, beep, xmlio
 
 log = logging.getLogger('bitten.master')
@@ -38,7 +39,6 @@
 DEFAULT_CHECK_INTERVAL = 120 # 2 minutes
 
 
-
 class Master(beep.Listener):
 
     def __init__(self, env_path, ip, port,
@@ -57,12 +57,11 @@
             for rev, format, path in snapshots:
                 self.snapshots[(config.name, rev, format)] = path
 
+        self._cleanup_orphaned_builds()
         self.schedule(self.check_interval, self._check_build_triggers)
 
     def close(self):
-        # Remove all pending builds
-        for build in Build.select(self.env, status=Build.PENDING):
-            build.delete()
+        self._cleanup_orphaned_builds()
         beep.Listener.close(self)
 
     def _check_build_triggers(self, when):
@@ -114,6 +113,15 @@
                     slave.send_initiation(build)
                     return
 
+    def _cleanup_orphaned_builds(self):
+        # Remove all pending or in-progress builds
+        db = self.env.get_db_cnx()
+        for build in Build.select(self.env, status=Build.IN_PROGRESS, db=db):
+            build.status = Build.PENDING
+            build.update(db=db)
+        for build in Build.select(self.env, status=Build.PENDING, db=db):
+            build.delete(db=db)
+
     def _cleanup_snapshots(self, when):
         log.debug('Checking for unused snapshot archives...')
         for (config, rev, format), path in self.snapshots.items():
@@ -230,8 +238,8 @@
             self.channel.send_rpy(msgno, beep.Payload(xml))
 
     def send_initiation(self, build):
-        log.debug('Initiating build of "%s" on slave %s', build.config,
-                  self.name)
+        log.info('Initiating build of "%s" on slave %s', build.config,
+                 self.name)
 
         def handle_reply(cmd, msgno, ansno, payload):
             if cmd == 'ERR':
@@ -276,58 +284,22 @@
                                 self.name, elem.gettext(),
                                 int(elem.attr['code']))
 
-            if cmd == 'ANS':
+            elif cmd == 'ANS':
+                assert payload.content_type == beep.BEEP_XML
                 db = self.env.get_db_cnx()
                 elem = xmlio.parse(payload.body)
-
                 if elem.name == 'started':
-                    build.slave = self.name
-                    build.slave_info.update(self.info)
-                    build.started = int(_parse_iso_datetime(elem.attr['time']))
-                    build.status = Build.IN_PROGRESS
-                    log.info('Slave %s started build %d ("%s" as of [%s])',
-                             self.name, build.id, build.config, build.rev)
-
+                    self._build_started(db, build, elem)
                 elif elem.name == 'step':
-                    log.info('Slave completed step "%s"', elem.attr['id'])
-                    step = BuildStep(self.env, build=build.id,
-                                     name=elem.attr['id'],
-                                     description=elem.attr.get('description'),
-                                     log=elem.gettext().strip())
-                    step.started = int(_parse_iso_datetime(elem.attr['time']))
-                    step.stopped = step.started + int(elem.attr['duration'])
-                    if elem.attr['result'] == 'failure':
-                        log.warning('Step failed: %s', elem.gettext())
-                        step.status = BuildStep.FAILURE
-                    else:
-                        step.status = BuildStep.SUCCESS
-                    step.insert(db=db)
-
+                    self._build_step_completed(db, build, elem)
                 elif elem.name == 'completed':
-                    log.info('Slave %s completed build %d ("%s" as of [%s])',
-                             self.name, build.id, build.config, build.rev)
-                    build.stopped = int(_parse_iso_datetime(elem.attr['time']))
-                    if elem.attr['result'] == 'failure':
-                        build.status = Build.FAILURE
-                    else:
-                        build.status = Build.SUCCESS
-
+                    self._build_completed(db, build, elem)
                 elif elem.name == 'aborted':
-                    log.info('Slave "%s" aborted build %d ("%s" as of [%s])',
-                             self.name, build.id, build.config, build.rev)
-                    build.slave = None
-                    build.started = 0
-                    build.status = Build.PENDING
-                    build.slave_info = {}
-                    for step in BuildStep.select(self.env, build=build.id,
-                                                 db=db):
-                        step.delete(db=db)
-
+                    self._build_aborted(db, build, elem)
                 elif elem.name == 'error':
                     build.status = Build.FAILURE
-
                 build.update(db=db)
-                db.commit()
+                db.commit()                    
 
         snapshot_format = {
             ('application/tar', 'bzip2'): 'bzip2',
@@ -342,6 +314,55 @@
                                content_encoding=encoding)
         self.channel.send_msg(message, handle_reply=handle_reply)
 
+    def _build_started(self, db, build, elem):
+        build.slave = self.name
+        build.slave_info.update(self.info)
+        build.started = int(_parse_iso_datetime(elem.attr['time']))
+        build.status = Build.IN_PROGRESS
+        log.info('Slave %s started build %d ("%s" as of [%s])',
+                 self.name, build.id, build.config, build.rev)
+
+    def _build_step_completed(self, db, build, elem):
+        log.debug('Slave completed step "%s"', elem.attr['id'])
+        step = BuildStep(self.env, build=build.id, name=elem.attr['id'],
+                         description=elem.attr.get('description'))
+        step.started = int(_parse_iso_datetime(elem.attr['time']))
+        step.stopped = step.started + int(elem.attr['duration'])
+        if elem.attr['result'] == 'failure':
+            log.warning('Step failed: %s', elem.gettext())
+            step.status = BuildStep.FAILURE
+        else:
+            step.status = BuildStep.SUCCESS
+
+        # TODO: Insert log messages into separate table, and also store reports
+        log_lines = []
+        for log_elem in elem.children('log'):
+            for messages_elem in log_elem.children('messages'):
+                for message_elem in messages_elem.children('message'):
+                    log_lines.append(message_elem.gettext())
+        step.log = '\n'.join(log_lines)
+
+        step.insert(db=db)
+
+    def _build_completed(self, db, build, elem):
+        log.info('Slave %s completed build %d ("%s" as of [%s])', self.name,
+                 build.id, build.config, build.rev)
+        build.stopped = int(_parse_iso_datetime(elem.attr['time']))
+        if elem.attr['result'] == 'failure':
+            build.status = Build.FAILURE
+        else:
+            build.status = Build.SUCCESS
+
+    def _build_aborted(self, db, build, elem):
+        log.info('Slave "%s" aborted build %d ("%s" as of [%s])',
+                 self.name, build.id, build.config, build.rev)
+        build.slave = None
+        build.started = 0
+        build.status = Build.PENDING
+        build.slave_info = {}
+        for step in BuildStep.select(self.env, build=build.id, db=db):
+            step.delete(db=db)
+
 
 def _parse_iso_datetime(string):
     """Minimal parser for ISO date-time strings.
--- a/bitten/recipe.py
+++ b/bitten/recipe.py
@@ -37,27 +37,18 @@
 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 = []
+        self.output = []
 
-    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:
-            log.warning(text)
-        else:
-            log.info(text)
-        self._log.append((self.current_step, self.current_function, level,
-                          time.time(), text))
+    def log(self, xml_elem):
+        self.output.append((Recipe.LOG, self.current_function, xml_elem))
+
+    def report(self, xml_elem):
+        self.output.append((Recipe.REPORT, self.current_function, xml_elem))
 
     def resolve(self, *path):
         return os.path.normpath(os.path.join(self.basedir, *path))
@@ -98,9 +89,10 @@
                 if self.onerror == 'fail':
                     raise BuildError, e
                 log.warning('Ignoring error in step %s (%s)', self.id, e)
-                return None
         finally:
             ctxt.current_step = None
+        while ctxt.output:
+            yield ctxt.output.pop()
 
     def _args(self, elem):
         return dict([(name.replace('-', '_'), value) for name, value
@@ -126,6 +118,9 @@
     Iterate over this object to get the individual build steps in the order they
     have been defined in the recipe file."""
 
+    LOG = 'log'
+    REPORT = 'report'
+
     def __init__(self, filename='recipe.xml', basedir=os.getcwd()):
         self.ctxt = Context(basedir)
         fd = file(self.ctxt.resolve(filename), 'r')
--- a/bitten/slave.py
+++ b/bitten/slave.py
@@ -150,15 +150,12 @@
                 log.info('Executing build step "%s"', step.id)
                 started = datetime.utcnow()
                 try:
-                    step.execute(recipe.ctxt)
-                    duration = datetime.utcnow() - started
-                    output = '\n'.join([record[-1] for record
-                                        in recipe.ctxt._log])
                     xml = xmlio.Element('step', id=step.id, result='success',
                                         description=step.description,
-                                        time=started.isoformat(),
-                                        duration=duration.seconds)[output]
-                    recipe.ctxt._log = []
+                                        time=started.isoformat())
+                    for type, function, output in step.execute(recipe.ctxt):
+                        xmlio.SubElement(xml, type, type=function)[output]
+                    xml.attr['duration'] = (datetime.utcnow() - started).seconds
                     self.channel.send_ans(msgno, beep.Payload(xml))
                 except (BuildError, InvalidRecipeError), e:
                     duration = datetime.utcnow() - started
@@ -170,7 +167,6 @@
                     self.channel.send_ans(msgno, beep.Payload(xml))
 
             log.info('Build completed')
-            recipe.ctxt._log = []
             xml = xmlio.Element('completed', time=datetime.utcnow().isoformat(),
                                 result=['success', 'failure'][failed])
             self.channel.send_ans(msgno, beep.Payload(xml))
--- a/bitten/util/xmlio.py
+++ b/bitten/util/xmlio.py
@@ -76,17 +76,17 @@
     >>> print Element('foo')['<bar a="3" b="4"><baz/></bar>']
     <foo><![CDATA[<bar a="3" b="4"><baz/></bar>]]></foo>
     """
-    __slots__ = ['name', 'attrs', 'children']
+    __slots__ = ['name', 'attr', 'children']
 
-    def __init__(self, *args, **attrs):
+    def __init__(self, *args, **attr):
         """Create an XML element using the specified tag name.
         
         The tag name must be supplied as the first positional argument. All
         keyword arguments following it are handled as attributes of the element.
         """
         self.name = args[0]
-        self.attrs = dict([(name, value) for name, value in attrs.items()
-                           if value is not None])
+        self.attr = dict([(name, value) for name, value in attr.items()
+                          if value is not None])
         self.children = []
 
     def __getitem__(self, children):
@@ -109,7 +109,7 @@
         """
         out.write('<')
         out.write(self.name)
-        for name, value in self.attrs.items():
+        for name, value in self.attr.items():
             out.write(' %s="%s"' % (name, self._escape_attr(value)))
         if self.children:
             out.write('>')
@@ -139,7 +139,7 @@
 
     __slots__ = []
 
-    def __init__(self, *args, **attrs):
+    def __init__(self, *args, **attr):
         """Create an XML element using the specified tag name.
         
         The first positional argument is the instance of the parent element that
@@ -148,7 +148,7 @@
         the element.
         """
         assert len(args) == 2
-        Element.__init__(self, args[1], **attrs)
+        Element.__init__(self, args[1], **attr)
         args[0].children.append(self)
 
 
--- a/recipe.xml
+++ b/recipe.xml
@@ -8,7 +8,7 @@
     </step>
 
     <step id="test" title="Unit tests"
-          description="Run unit tests and trace code coverage">
+          description="Run unit tests and record code coverage">
         <python:distutils command="unittest"/>
         <reports>
             <python:unittest file="build/test-results.xml"/>
--- a/scripts/build.py
+++ b/scripts/build.py
@@ -43,7 +43,7 @@
     log.setLevel(options.loglevel)
     handler = logging.StreamHandler()
     handler.setLevel(options.loglevel)
-    formatter = logging.Formatter('[%(levelname)-8s] %(message)s')
+    formatter = logging.Formatter('%(message)s')
     handler.setFormatter(formatter)
     log.addHandler(handler)
 
@@ -51,9 +51,10 @@
     recipe = Recipe()
     for step in recipe:
         if not steps_to_run or step.id in steps_to_run:
+            print
             print '-->', step.description or step.id
-            step.execute(recipe.ctxt)
-            print
+            for type, function, output in step.execute(recipe.ctxt):
+                pass
             if step.id in steps_to_run:
                 steps_to_run[step.id] = True
 
Copyright (C) 2012-2017 Edgewall Software