changeset 82:01200c88ddb0

Include timing information in the build messages transmitted from slave to master for better accuracy.
author cmlenz
date Fri, 08 Jul 2005 10:54:19 +0000
parents 7129b8a2f125
children 42970c14524a
files bitten/master.py bitten/slave.py bitten/trac_ext/web_ui.py templates/build.cs
diffstat 4 files changed, 67 insertions(+), 47 deletions(-) [+]
line wrap: on
line diff
--- a/bitten/master.py
+++ b/bitten/master.py
@@ -18,6 +18,7 @@
 #
 # Author: Christopher Lenz <cmlenz@gmx.de>
 
+from itertools import ifilter
 import logging
 import os.path
 import re
@@ -70,7 +71,7 @@
                                               platform.id)
                         if not list(builds):
                             logging.info('Enqueuing build of configuration "%s"'
-                                         'at revision [%s] on %s', config.name,
+                                         ' at revision [%s] on %s', config.name,
                                          rev, platform.name)
                             build = Build(self.env)
                             build.config = config.name
@@ -96,13 +97,9 @@
                 platform = TargetPlatform(self.env, build.platform)
                 logging.debug('Matching slave %s against rules: %s',
                               slave.name, platform.rules)
-                for property, pattern in platform.rules:
-                    if not property or not pattern:
-                        continue
+                for property, pattern in ifilter(None, platform.rules):
                     try:
-                        if not re.match(pattern, slave.props.get(property)):
-                            logging.debug('Rule (%s, %s) did not match "%s"',
-                                          property, pattern, slave.props.get(property))
+                        if not re.match(pattern, slave.info.get(property)):
                             matches_platform = False
                             break
                     except re.error, e:
@@ -147,7 +144,7 @@
         self.env = self.master.env
         assert self.env
         self.name = None
-        self.props = {}
+        self.info = {}
 
     def handle_disconnect(self):
         if self.name is None:
@@ -176,13 +173,13 @@
             self.name = elem.attr['name']
             for child in elem.children():
                 if child.name == 'platform':
-                    self.props[Build.MACHINE] = child.gettext()
-                    self.props[Build.PROCESSOR] = child.attr.get('processor')
+                    self.info[Build.MACHINE] = child.gettext()
+                    self.info[Build.PROCESSOR] = child.attr.get('processor')
                 elif child.name == 'os':
-                    self.props[Build.OS_NAME] = child.gettext()
-                    self.props[Build.OS_FAMILY] = child.attr.get('family')
-                    self.props[Build.OS_VERSION] = child.attr.get('version')
-            self.props[Build.IP_ADDRESS] = self.session.addr[0]
+                    self.info[Build.OS_NAME] = child.gettext()
+                    self.info[Build.OS_FAMILY] = child.attr.get('family')
+                    self.info[Build.OS_VERSION] = child.attr.get('version')
+            self.info[Build.IP_ADDRESS] = self.session.addr[0]
 
             self.name = elem.attr['name']
             self.master.slaves[self.name] = self
@@ -200,8 +197,9 @@
                 if msg.get_content_type() == beep.BEEP_XML:
                     elem = xmlio.parse(msg.get_payload())
                     if elem.name == 'error':
-                        logging.warning('Slave refused build request: %s (%d)',
-                                        elem.gettext(), int(elem.attr['code']))
+                        logging.warning('Slave %s refused build request: '
+                                        '%s (%d)', self.name, elem.gettext(),
+                                        int(elem.attr['code']))
                 return
 
             elem = xmlio.parse(msg.get_payload())
@@ -233,16 +231,17 @@
                 assert msg.get_content_type() == beep.BEEP_XML
                 elem = xmlio.parse(msg.get_payload())
                 if elem.name == 'error':
-                    logging.warning('Slave did not accept archive: %s (%d)',
-                                    elem.gettext(), int(elem.attr['code']))
+                    logging.warning('Slave %s did not accept archive: %s (%d)',
+                                    self.name, elem.gettext(),
+                                    int(elem.attr['code']))
 
             if cmd == 'ANS':
                 elem = xmlio.parse(msg.get_payload())
 
                 if elem.name == 'started':
                     build.slave = self.name
-                    build.slave_info.update(self.props)
-                    build.started = int(time.time())
+                    build.slave_info.update(self.info)
+                    build.started = int(_parse_iso_datetime(elem.attr['time']))
                     build.status = Build.IN_PROGRESS
                     build.update()
                     logging.info('Slave %s started build of "%s" as of [%s]',
@@ -254,7 +253,8 @@
                     step.build = build.id
                     step.name = elem.attr['id']
                     step.description = elem.attr.get('description')
-                    step.stopped = int(time.time())
+                    step.started = int(_parse_iso_datetime(elem.attr['time']))
+                    step.stopped = step.started + int(elem.attr['duration'])
                     step.log = elem.gettext().strip()
                     if elem.attr['result'] == 'failure':
                         logging.warning('Step failed: %s', elem.gettext())
@@ -263,6 +263,15 @@
                         step.status = BuildStep.SUCCESS
                     step.insert()
 
+                elif elem.name == 'completed':
+                    logging.info('Slave %s completed build of "%s" as of [%s]',
+                                 self.name, 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
+
                 elif elem.name == 'aborted':
                     logging.info('Slave "%s" aborted build', self.name)
                     build.slave = None
@@ -274,25 +283,6 @@
 
                 build.update()
 
-            elif cmd == 'NUL':
-                if build.status != Build.PENDING: # Completed
-                    logging.info('Slave %s completed build of "%s" as of [%s]',
-                                 self.name, build.config, build.rev)
-                    build.stopped = int(time.time())
-                    if build.status is Build.IN_PROGRESS:
-                        # Find out whether the build failed or succeeded
-                        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
         #       asyncore push_with_producer()
         snapshot_path = self.master.get_snapshot(build, type, encoding)
@@ -303,6 +293,22 @@
         self.channel.send_msg(message, handle_reply=handle_reply)
 
 
+def _parse_iso_datetime(string):
+    """Minimal parser for ISO date-time strings.
+    
+    Return the time as floating point number. Only handles UTC timestamps
+    without time zone information."""
+    try:
+        string = string.split('.', 1)[0] # strip out microseconds
+        secs = time.mktime(time.strptime(string, '%Y-%m-%dT%H:%M:%S'))
+        tzoffset = time.timezone
+        if time.daylight:
+            tzoffset = time.altzone
+        return secs - tzoffset
+    except ValueError, e:
+        raise ValueError, 'Invalid ISO date/time %s (%s)' % (string, e)
+
+
 def main():
     from bitten import __version__ as VERSION
     from optparse import OptionParser
--- a/bitten/slave.py
+++ b/bitten/slave.py
@@ -18,12 +18,12 @@
 #
 # Author: Christopher Lenz <cmlenz@gmx.de>
 
+from datetime import datetime
 import logging
 import os
 import platform
 import sys
 import tempfile
-import time
 
 from bitten.build import BuildError
 from bitten.recipe import Recipe, InvalidRecipeError
@@ -134,25 +134,38 @@
         try:
             recipe = Recipe(recipe_path, basedir)
 
-            xml = xmlio.Element('started')
+            xml = xmlio.Element('started', time=datetime.utcnow().isoformat())
             self.channel.send_ans(msgno, beep.MIMEMessage(xml))
 
+            failed = False
             for step in recipe:
                 logging.info('Executing build step "%s"', step.id)
+                started = datetime.utcnow()
                 try:
                     step.execute(recipe.ctxt)
+                    duration = datetime.utcnow() - started
+                    log = '\n'.join([record[-1] for record in recipe.ctxt._log])
                     xml = xmlio.Element('step', id=step.id, result='success',
-                                        description=step.description)[
-                        '\n'.join([record[-1] for record in recipe.ctxt._log])
-                    ]
+                                        description=step.description,
+                                        time=started.isoformat(),
+                                        duration=duration.seconds)[log]
                     recipe.ctxt._log = []
                     self.channel.send_ans(msgno, beep.MIMEMessage(xml))
                 except (BuildError, InvalidRecipeError), e:
+                    duration = datetime.utcnow() - started
+                    failed = True
                     xml = xmlio.Element('step', id=step.id, result='failure',
-                                        description=step.description)[e]
+                                        description=step.description,
+                                        time=started.isoformat(),
+                                        duration=duration.seconds)[e]
                     self.channel.send_ans(msgno, beep.MIMEMessage(xml))
 
             logging.info('Build completed')
+            recipe.ctxt._log = []
+            xml = xmlio.Element('completed', time=datetime.utcnow().isoformat(),
+                                result=['success', 'failure'][failed])
+            self.channel.send_ans(msgno, beep.MIMEMessage(xml))
+
             self.channel.send_nul(msgno)
 
         except InvalidRecipeError, e:
--- a/bitten/trac_ext/web_ui.py
+++ b/bitten/trac_ext/web_ui.py
@@ -424,6 +424,7 @@
         for step in BuildStep.select(self.env, build=build.id):
             steps.append({
                 'name': step.name, 'description': step.description,
+                'duration': pretty_timedelta(step.started, step.stopped),
                 'log': step.log
             })
         hdf['steps'] = steps
--- a/templates/build.cs
+++ b/templates/build.cs
@@ -157,7 +157,7 @@
    <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>
+   <h2><?cs var:step.name ?> (<?cs var:step.duration ?>)</h2>
    <p><?cs var:step.description ?></p>
    <pre class="log"><?cs var:step.log ?></pre><?cs
   /each ?><?cs
Copyright (C) 2012-2017 Edgewall Software