# HG changeset patch # User wbell # Date 1272121883 0 # Node ID 5f0cfee445409ae34c02154642b4f2b4f716d3f8 # Parent b2272caf5ac440db7f9018e8f5d97a0460c66fa2 Add new last_activity field to build. I considered reusing stopped, but this seemed cleaner and more obvious, which seems like the right way to go. On the completion of every step, last activity is updated to the current time. All orphaning/invalidation based on slave_timeout happens based on that time, not started. Previously, builds were orphaned if it had been more than slave_timeout (config setting) seconds since they had started, now it's since the last interaction (which is actually what the documentation on the field already says.) This requires a database upgrade. Thanks to Hodgestar for comments. Closes #222. Refs #411. diff --git a/bitten/master.py b/bitten/master.py --- a/bitten/master.py +++ b/bitten/master.py @@ -55,7 +55,7 @@ build_all = BoolOption('bitten', 'build_all', False, doc= """Whether to request builds of older revisions even if a younger revision has already been built.""") - + stabilize_wait = IntOption('bitten', 'stabilize_wait', 0, doc= """The time in seconds to wait for the repository to stabilize before queuing up a new build. This allows time for developers to check in @@ -70,7 +70,7 @@ """The directory on the server in which client log files will be stored.""") quick_status = BoolOption('bitten', 'quick_status', False, doc= - """Whether to show the current build status withing the Trac main + """Whether to show the current build status withing the Trac main navigation bar""") def __init__(self): @@ -151,7 +151,7 @@ self._send_response(req, code, body=message, headers=headers) def _process_build_creation(self, req, slave_token): - queue = BuildQueue(self.env, build_all=self.build_all, + queue = BuildQueue(self.env, build_all=self.build_all, stabilize_wait=self.stabilize_wait, timeout=self.slave_timeout) queue.populate() @@ -224,6 +224,7 @@ self.log.info('Build slave %r initiated build %d', build.slave, build.id) build.started = int(time.time()) + build.last_activity = build.started build.update() for listener in BuildSystem(self.env).listeners: @@ -348,11 +349,12 @@ attachment.insert(filename, fileobj, fileobj.len, db=db) # If this was the last step in the recipe we mark the build as - # completed + # completed otherwise just update last_activity if last_step: self.log.info('Slave %s completed build %d ("%s" as of [%s])', build.slave, build.id, build.config, build.rev) build.stopped = step.stopped + build.last_activity = build.stopped # Determine overall outcome of the build by checking the outcome # of the individual steps against the "onerror" specification of @@ -369,6 +371,9 @@ build.update(db=db) else: + build.last_activity = step.stopped + build.update(db=db) + # start the next step. for num, recipe_step in enumerate(recipe): if num == index + 1: diff --git a/bitten/model.py b/bitten/model.py --- a/bitten/model.py +++ b/bitten/model.py @@ -373,6 +373,7 @@ Column('rev_time', type='int'), Column('platform', type='int'), Column('slave'), Column('started', type='int'), Column('stopped', type='int'), Column('status', size=1), + Column('last_activity', type='int'), Index(['config', 'rev', 'platform'], unique=True) ], Table('bitten_slave', key=('build', 'propname'))[ @@ -397,7 +398,8 @@ TOKEN = 'token' def __init__(self, env, config=None, rev=None, platform=None, slave=None, - started=0, stopped=0, rev_time=0, status=PENDING): + started=0, stopped=0, last_activity=0, + rev_time=0, status=PENDING): """Initialize a new build with the specified attributes. To actually create this build in the database, the `insert` method needs @@ -411,6 +413,7 @@ self.slave = slave self.started = started or 0 self.stopped = stopped or 0 + self.last_activity = last_activity or 0 self.rev_time = rev_time self.status = status self.slave_info = {} @@ -466,11 +469,12 @@ cursor = db.cursor() cursor.execute("INSERT INTO bitten_build (config,rev,rev_time,platform," - "slave,started,stopped,status) " - "VALUES (%s,%s,%s,%s,%s,%s,%s,%s)", + "slave,started,stopped,last_activity,status) " + "VALUES (%s,%s,%s,%s,%s,%s,%s,%s,%s)", (self.config, self.rev, int(self.rev_time), self.platform, self.slave or '', self.started or 0, - self.stopped or 0, self.status)) + self.stopped or 0, self.last_activity or 0, + self.status)) self.id = db.get_last_id(cursor, 'bitten_build') if self.slave_info: cursor.executemany("INSERT INTO bitten_slave VALUES (%s,%s,%s)", @@ -497,9 +501,10 @@ cursor = db.cursor() cursor.execute("UPDATE bitten_build SET slave=%s,started=%s," - "stopped=%s,status=%s WHERE id=%s", + "stopped=%s,last_activity=%s,status=%s WHERE id=%s", (self.slave or '', self.started or 0, - self.stopped or 0, self.status, self.id)) + self.stopped or 0, self.last_activity or 0, + self.status, self.id)) cursor.execute("DELETE FROM bitten_slave WHERE build=%s", (self.id,)) if self.slave_info: cursor.executemany("INSERT INTO bitten_slave VALUES (%s,%s,%s)", @@ -515,7 +520,8 @@ cursor = db.cursor() cursor.execute("SELECT config,rev,rev_time,platform,slave,started," - "stopped,status FROM bitten_build WHERE id=%s", (id,)) + "stopped,last_activity,status FROM bitten_build WHERE " + "id=%s", (id,)) row = cursor.fetchone() if not row: return None @@ -523,7 +529,9 @@ build = Build(env, config=row[0], rev=row[1], rev_time=int(row[2]), platform=int(row[3]), slave=row[4], started=row[5] and int(row[5]) or 0, - stopped=row[6] and int(row[6]) or 0, status=row[7]) + stopped=row[6] and int(row[6]) or 0, + last_activity=row[7] and int(row[7]) or 0, + status=row[8]) build.id = int(id) cursor.execute("SELECT propname,propvalue FROM bitten_slave " "WHERE build=%s", (id,)) @@ -1033,4 +1041,4 @@ schema = BuildConfig._schema + TargetPlatform._schema + Build._schema + \ BuildStep._schema + BuildLog._schema + Report._schema -schema_version = 11 +schema_version = 12 diff --git a/bitten/queue.py b/bitten/queue.py --- a/bitten/queue.py +++ b/bitten/queue.py @@ -24,6 +24,7 @@ import time from trac.util.datefmt import to_timestamp +from trac.util import pretty_timedelta, format_datetime from trac.attachment import Attachment @@ -276,16 +277,21 @@ db = self.env.get_db_cnx() now = int(time.time()) for build in Build.select(self.env, status=Build.IN_PROGRESS, db=db): - if now - build.started < self.timeout: + if now - build.last_activity < self.timeout: # This build has not reached the timeout yet, assume it's still # being executed - # FIXME: ideally, we'd base this check on the last activity on - # the build, not the start time continue + + self.log.info('Orphaning build %d. Last activity was %s (%s)' % \ + (build.id, format_datetime(build.last_activity), + pretty_timedelta(build.last_activity))) + build.status = Build.PENDING build.slave = None build.slave_info = {} build.started = 0 + build.stopped = 0 + build.last_activity = 0 for step in list(BuildStep.select(self.env, build=build.id, db=db)): step.delete(db=db) build.update(db=db) diff --git a/bitten/tests/queue.py b/bitten/tests/queue.py --- a/bitten/tests/queue.py +++ b/bitten/tests/queue.py @@ -392,12 +392,12 @@ platform.insert() build1 = Build(self.env, config='test', platform=platform.id, rev=123, rev_time=42, status=Build.IN_PROGRESS, slave='heinz', - started=time.time() - 600) # Started ten minutes ago + last_activity=time.time() - 600) # active ten minutes ago build1.insert() build2 = Build(self.env, config='test', platform=platform.id, rev=124, rev_time=42, status=Build.IN_PROGRESS, slave='heinz', - started=time.time() - 60) # Started a minute ago + last_activity=time.time() - 60) # active a minute ago build2.insert() queue = BuildQueue(self.env, timeout=300) # 5 minutes timeout diff --git a/bitten/tests/upgrades.py b/bitten/tests/upgrades.py --- a/bitten/tests/upgrades.py +++ b/bitten/tests/upgrades.py @@ -170,6 +170,7 @@ 'old_log_v5', 'old_log_v8', 'old_rule', + 'old_build_v11', ] basic_data = [ diff --git a/bitten/upgrades.py b/bitten/upgrades.py --- a/bitten/upgrades.py +++ b/bitten/upgrades.py @@ -125,6 +125,34 @@ "max_rev,label,description) SELECT name,path,0,'',NULL," "NULL,label,description FROM old_config") +def add_last_activity_to_build(env, db): + """Add a column for storing the last activity to the build table.""" + from trac.db import Table, Column, Index + cursor = db.cursor() + + build_table_schema_v12 = Table('bitten_build', key='id')[ + 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('last_activity', type='int'), + Index(['config', 'rev', 'platform'], unique=True) + ] + + cursor.execute("CREATE TEMPORARY TABLE old_build_v11 AS " + "SELECT * FROM bitten_build") + cursor.execute("DROP TABLE bitten_build") + + connector, _ = DatabaseManager(env)._get_connector() + for stmt in connector.to_sql(build_table_schema_v12): + cursor.execute(stmt) + + # it's safe to make the last activity the stop time of the build + cursor.execute("INSERT INTO bitten_build (config,rev,rev_time,platform," + "slave,started,stopped,last_activity,status) " + "SELECT config,rev,rev_time,platform," + "slave,started,stopped,stopped,status FROM old_build_v11") + def add_config_to_reports(env, db): """Add the name of the build configuration as metadata to report documents stored in the BDB XML database.""" @@ -199,7 +227,7 @@ def xmldb_to_db(env, db): """Migrate report data from Berkeley DB XML to SQL database. - + Depending on the number of reports stored, this might take rather long. After the upgrade is done, the bitten.dbxml file (and any BDB XML log files) may be deleted. BDB XML is no longer used by Bitten. @@ -562,4 +590,5 @@ 9: [recreate_rule_with_int_id], 10: [add_config_platform_rev_index_to_build, fix_sequences], 11: [fix_log_levels_misnaming, remove_stray_log_levels_files], + 12: [add_last_activity_to_build], } diff --git a/bitten/web_ui.py b/bitten/web_ui.py --- a/bitten/web_ui.py +++ b/bitten/web_ui.py @@ -676,7 +676,9 @@ step.delete(db=db) build.slave = None - build.started = build.stopped = 0 + build.started = 0 + build.stopped = 0 + build.last_activity = 0 build.status = Build.PENDING build.slave_info = {} build.update()