def test_run_result_key_to_performance_stats_key(self):
request_key = task_pack.unpack_request_key('11')
result_summary_key = task_pack.request_key_to_result_summary_key(
request_key)
run_result_key = task_pack.result_summary_key_to_run_result_key(
result_summary_key, 1)
perf_stats_key = task_pack.run_result_key_to_performance_stats_key(
run_result_key)
self.assertEqual('PerformanceStats',perf_stats_key.kind())
def test_run_result_key_to_performance_stats_key(self):
request_key = task_pack.unpack_request_key('11')
result_summary_key = task_pack.request_key_to_result_summary_key(
request_key)
run_result_key = task_pack.result_summary_key_to_run_result_key(
result_summary_key, 1)
perf_stats_key = task_pack.run_result_key_to_performance_stats_key(
run_result_key)
self.assertEqual('PerformanceStats', perf_stats_key.kind())
def run():
"""Returns tuple(TaskRunResult, bool(completed), str(error)).
Any error is returned as a string to be passed to logging.error() instead of
logging inside the transaction for performance.
"""
# 2 consecutive GETs, one PUT.
run_result_future = run_result_key.get_async()
result_summary_future = result_summary_key.get_async()
run_result = run_result_future.get_result()
if not run_result:
result_summary_future.wait()
return None, None, 'is missing'
if run_result.bot_id != bot_id:
result_summary_future.wait()
return None, None, (
'expected bot (%s) but had update from bot %s' %
(run_result.bot_id, bot_id))
if not run_result.started_ts:
return None, None, 'TaskRunResult is broken; %s' % (
run_result.to_dict())
# Assumptions:
# - duration and exit_code are both set or not set.
# - same for run_result.
if exit_code is not None:
if run_result.exit_code is not None:
# This happens as an HTTP request is retried when the DB write succeeded
# but it still returned HTTP 500.
if run_result.exit_code != exit_code:
result_summary_future.wait()
return None, None, 'got 2 different exit_code; %s then %s' % (
run_result.exit_code, exit_code)
if run_result.duration != duration:
result_summary_future.wait()
return None, None, 'got 2 different durations; %s then %s' % (
run_result.duration, duration)
else:
run_result.duration = duration
run_result.exit_code = exit_code
if outputs_ref:
run_result.outputs_ref = outputs_ref
if cipd_pins:
run_result.cipd_pins = cipd_pins
if run_result.state in task_result.State.STATES_RUNNING:
if hard_timeout or io_timeout:
run_result.state = task_result.State.TIMED_OUT
run_result.completed_ts = now
elif run_result.exit_code is not None:
run_result.state = task_result.State.COMPLETED
run_result.completed_ts = now
run_result.signal_server_version(server_version)
run_result.validate(request)
to_put = [run_result]
if output:
# This does 1 multi GETs. This also modifies run_result in place.
to_put.extend(
run_result.append_output(output, output_chunk_start or 0))
if performance_stats:
performance_stats.key = task_pack.run_result_key_to_performance_stats_key(
run_result.key)
to_put.append(performance_stats)
run_result.cost_usd = max(cost_usd, run_result.cost_usd or 0.)
run_result.modified_ts = now
result_summary = result_summary_future.get_result()
if (result_summary.try_number
and result_summary.try_number > run_result.try_number):
# The situation where a shard is retried but the bot running the previous
# try somehow reappears and reports success, the result must still show
# the last try's result. We still need to update cost_usd manually.
result_summary.costs_usd[run_result.try_number -
1] = run_result.cost_usd
result_summary.modified_ts = now
else:
result_summary.set_from_run_result(run_result, request)
result_summary.validate(request)
to_put.append(result_summary)
ndb.put_multi(to_put)
return result_summary, run_result, None
def performance_stats_key(self):
key = self.run_result_key
if key:
return task_pack.run_result_key_to_performance_stats_key(key)
def performance_stats_key(self):
return task_pack.run_result_key_to_performance_stats_key(self.key)
def test_integration(self):
# Creates a TaskRequest, along its TaskResultSummary and TaskToRun. Have a
# bot reap the task, and complete the task. Ensure the resulting
# TaskResultSummary and TaskRunResult are properly updated.
request = mkreq(_gen_request())
result_summary = task_result.new_result_summary(request)
to_run = task_to_run.new_task_to_run(request)
result_summary.modified_ts = utils.utcnow()
ndb.transaction(lambda: ndb.put_multi([result_summary, to_run]))
expected = {
'abandoned_ts': None,
'bot_dimensions': None,
'bot_id': None,
'bot_version': None,
'cipd_pins': None,
'children_task_ids': [],
'completed_ts': None,
'costs_usd': [],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': None,
'exit_code': None,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': self.now,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [],
'started_ts': None,
'state': task_result.State.PENDING,
'try_number': None,
'tags': [
u'pool:default',
u'priority:50',
u'service_account:none',
u'tag:1',
u'user:Jesus',
],
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.to_dict())
# Nothing changed 2 secs later except latency.
self.mock_now(self.now, 2)
self.assertEqual(expected, result_summary.to_dict())
# Task is reaped after 2 seconds (4 secs total).
reap_ts = self.now + datetime.timedelta(seconds=4)
self.mock_now(reap_ts)
to_run.queue_number = None
to_run.put()
run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
run_result.modified_ts = utils.utcnow()
result_summary.set_from_run_result(run_result, request)
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = {
'abandoned_ts': None,
'bot_dimensions': {},
'bot_id': u'localhost',
'bot_version': u'abc',
'cipd_pins': None,
'children_task_ids': [],
'completed_ts': None,
'costs_usd': [0.],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': None,
'exit_code': None,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': reap_ts,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [u'v1a'],
'started_ts': reap_ts,
'state': task_result.State.RUNNING,
'tags': [
u'pool:default',
u'priority:50',
u'service_account:none',
u'tag:1',
u'user:Jesus',
],
'try_number': 1,
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.key.get().to_dict())
# Task completed after 2 seconds (6 secs total), the task has been running
# for 2 seconds.
complete_ts = self.now + datetime.timedelta(seconds=6)
self.mock_now(complete_ts)
run_result.completed_ts = complete_ts
run_result.duration = 0.1
run_result.exit_code = 0
run_result.state = task_result.State.COMPLETED
run_result.modified_ts = utils.utcnow()
task_result.PerformanceStats(
key=task_pack.run_result_key_to_performance_stats_key(run_result.key),
bot_overhead=0.1,
isolated_download=task_result.OperationStats(
duration=0.05, initial_number_items=10, initial_size=10000,
items_cold='foo', items_hot='bar'),
isolated_upload=task_result.OperationStats(
duration=0.01, items_cold='foo')).put()
ndb.transaction(lambda: ndb.put_multi(run_result.append_output('foo', 0)))
result_summary.set_from_run_result(run_result, request)
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = {
'abandoned_ts': None,
'bot_dimensions': {},
'bot_id': u'localhost',
'bot_version': u'abc',
'cipd_pins': None,
'children_task_ids': [],
'completed_ts': complete_ts,
'costs_usd': [0.],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': 0.1,
'exit_code': 0,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': complete_ts,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [u'v1a'],
'started_ts': reap_ts,
'state': task_result.State.COMPLETED,
'tags': [
u'pool:default',
u'priority:50',
u'service_account:none',
u'tag:1',
u'user:Jesus',
],
'try_number': 1,
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.key.get().to_dict())
expected = {
'bot_overhead': 0.1,
'isolated_download': {
'duration': 0.05,
'initial_number_items': 10,
'initial_size': 10000,
'items_cold': 'foo',
'items_hot': 'bar',
},
'isolated_upload': {
'duration': 0.01,
'initial_number_items': None,
'initial_size': None,
'items_cold': 'foo',
'items_hot': None,
},
'package_installation': {
'duration': None,
'initial_number_items': None,
'initial_size': None,
'items_cold': None,
'items_hot': None,
},
}
self.assertEqual(expected, result_summary.performance_stats.to_dict())
self.assertEqual('foo', result_summary.get_output())
self.assertEqual(
datetime.timedelta(seconds=2),
result_summary.duration_as_seen_by_server)
self.assertEqual(
datetime.timedelta(seconds=0.1),
result_summary.duration_now(utils.utcnow()))
self.assertEqual(
datetime.timedelta(seconds=4), result_summary.pending)
self.assertEqual(
datetime.timedelta(seconds=4),
result_summary.pending_now(utils.utcnow()))
self.assertEqual(
task_pack.pack_result_summary_key(result_summary.key),
result_summary.task_id)
self.assertEqual(complete_ts, result_summary.ended_ts)
self.assertEqual(
task_pack.pack_run_result_key(run_result.key),
run_result.task_id)
self.assertEqual(complete_ts, run_result.ended_ts)
def test_integration(self):
# Creates a TaskRequest, along its TaskResultSummary and TaskToRun. Have a
# bot reap the task, and complete the task. Ensure the resulting
# TaskResultSummary and TaskRunResult are properly updated.
request = task_request.make_request(_gen_request(), True)
result_summary = task_result.new_result_summary(request)
to_run = task_to_run.new_task_to_run(request)
result_summary.modified_ts = utils.utcnow()
ndb.transaction(lambda: ndb.put_multi([result_summary, to_run]))
expected = {
'abandoned_ts': None,
'bot_dimensions': None,
'bot_id': None,
'bot_version': None,
'children_task_ids': [],
'completed_ts': None,
'costs_usd': [],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': None,
'exit_code': None,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': self.now,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [],
'started_ts': None,
'state': task_result.State.PENDING,
'try_number': None,
'tags': [
u'pool:default',
u'priority:50',
u'tag:1',
u'user:Jesus',
],
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.to_dict())
# Nothing changed 2 secs later except latency.
self.mock_now(self.now, 2)
self.assertEqual(expected, result_summary.to_dict())
# Task is reaped after 2 seconds (4 secs total).
reap_ts = self.now + datetime.timedelta(seconds=4)
self.mock_now(reap_ts)
to_run.queue_number = None
to_run.put()
run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
run_result.modified_ts = utils.utcnow()
result_summary.set_from_run_result(run_result, request)
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = {
'abandoned_ts': None,
'bot_dimensions': {},
'bot_id': u'localhost',
'bot_version': u'abc',
'children_task_ids': [],
'completed_ts': None,
'costs_usd': [0.],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': None,
'exit_code': None,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': reap_ts,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [u'v1a'],
'started_ts': reap_ts,
'state': task_result.State.RUNNING,
'tags': [
u'pool:default',
u'priority:50',
u'tag:1',
u'user:Jesus',
],
'try_number': 1,
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.key.get().to_dict())
# Task completed after 2 seconds (6 secs total), the task has been running
# for 2 seconds.
complete_ts = self.now + datetime.timedelta(seconds=6)
self.mock_now(complete_ts)
run_result.completed_ts = complete_ts
run_result.duration = 0.1
run_result.exit_code = 0
run_result.state = task_result.State.COMPLETED
run_result.modified_ts = utils.utcnow()
task_result.PerformanceStats(
key=task_pack.run_result_key_to_performance_stats_key(run_result.key),
bot_overhead=0.1,
isolated_download=task_result.IsolatedOperation(
duration=0.05, initial_number_items=10, initial_size=10000,
items_cold='foo', items_hot='bar'),
isolated_upload=task_result.IsolatedOperation(
duration=0.01, items_cold='foo')).put()
ndb.transaction(lambda: ndb.put_multi(run_result.append_output('foo', 0)))
result_summary.set_from_run_result(run_result, request)
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = {
'abandoned_ts': None,
'bot_dimensions': {},
'bot_id': u'localhost',
'bot_version': u'abc',
'children_task_ids': [],
'completed_ts': complete_ts,
'costs_usd': [0.],
'cost_saved_usd': None,
'created_ts': self.now,
'deduped_from': None,
'duration': 0.1,
'exit_code': 0,
'failure': False,
'id': '1d69b9f088008810',
'internal_failure': False,
'modified_ts': complete_ts,
'name': u'Request name',
'outputs_ref': None,
'properties_hash': None,
'server_versions': [u'v1a'],
'started_ts': reap_ts,
'state': task_result.State.COMPLETED,
'tags': [
u'pool:default',
u'priority:50',
u'tag:1',
u'user:Jesus',
],
'try_number': 1,
'user': u'Jesus',
}
self.assertEqual(expected, result_summary.key.get().to_dict())
expected = {
'bot_overhead': 0.1,
'isolated_download': {
'duration': 0.05,
'initial_number_items': 10,
'initial_size': 10000,
'items_cold': 'foo',
'items_hot': 'bar',
},
'isolated_upload': {
'duration': 0.01,
'initial_number_items': None,
'initial_size': None,
'items_cold': 'foo',
'items_hot': None,
},
}
self.assertEqual(expected, result_summary.performance_stats.to_dict())
self.assertEqual('foo', result_summary.get_output())
self.assertEqual(
datetime.timedelta(seconds=2),
result_summary.duration_as_seen_by_server)
self.assertEqual(
datetime.timedelta(seconds=0.1),
result_summary.duration_now(utils.utcnow()))
self.assertEqual(
datetime.timedelta(seconds=4), result_summary.pending)
self.assertEqual(
datetime.timedelta(seconds=4),
result_summary.pending_now(utils.utcnow()))
self.assertEqual(
task_pack.pack_result_summary_key(result_summary.key),
result_summary.task_id)
self.assertEqual(complete_ts, result_summary.ended_ts)
self.assertEqual(
task_pack.pack_run_result_key(run_result.key),
run_result.task_id)
self.assertEqual(complete_ts, run_result.ended_ts)
def _bot_update_tx(
run_result_key, bot_id, output, output_chunk_start, exit_code, duration,
hard_timeout, io_timeout, cost_usd, outputs_ref, cipd_pins,
performance_stats, now, result_summary_key, server_version, request):
"""Runs the transaction for bot_update_task().
Returns tuple(TaskRunResult, bool(completed), str(error)).
Any error is returned as a string to be passed to logging.error() instead of
logging inside the transaction for performance.
"""
# 2 or 3 consecutive GETs, one PUT.
#
# Assumptions:
# - duration and exit_code are both set or not set. That's not always true for
# TIMED_OUT/KILLED.
# - same for run_result.
# - if one of hard_timeout or io_timeout is set, duration is also set.
# - hard_timeout or io_timeout can still happen in the case of killing. This
# still needs to result in KILLED, not TIMED_OUT.
run_result_future = run_result_key.get_async()
result_summary_future = result_summary_key.get_async()
run_result = run_result_future.get_result()
if not run_result:
result_summary_future.wait()
return None, None, 'is missing'
if run_result.bot_id != bot_id:
result_summary_future.wait()
return None, None, (
'expected bot (%s) but had update from bot %s' % (
run_result.bot_id, bot_id))
if not run_result.started_ts:
return None, None, 'TaskRunResult is broken; %s' % (
run_result.to_dict())
if exit_code is not None:
if run_result.exit_code is not None:
# This happens as an HTTP request is retried when the DB write succeeded
# but it still returned HTTP 500.
if run_result.exit_code != exit_code:
result_summary_future.wait()
return None, None, 'got 2 different exit_code; %s then %s' % (
run_result.exit_code, exit_code)
if run_result.duration != duration:
result_summary_future.wait()
return None, None, 'got 2 different durations; %s then %s' % (
run_result.duration, duration)
else:
run_result.duration = duration
run_result.exit_code = exit_code
if outputs_ref:
run_result.outputs_ref = outputs_ref
if cipd_pins:
run_result.cipd_pins = cipd_pins
if run_result.state in task_result.State.STATES_RUNNING:
# Task was still registered as running. Look if it should be terminated now.
if run_result.killing:
if duration is not None:
# A user requested to cancel the task while it was running. Since the
# task is now stopped, we can tag the task result as KILLED.
run_result.killing = False
run_result.state = task_result.State.KILLED
else:
if hard_timeout or io_timeout:
run_result.state = task_result.State.TIMED_OUT
run_result.completed_ts = now
elif run_result.exit_code is not None:
run_result.state = task_result.State.COMPLETED
run_result.completed_ts = now
run_result.signal_server_version(server_version)
to_put = [run_result]
if output:
# This does 1 multi GETs. This also modifies run_result in place.
to_put.extend(run_result.append_output(output, output_chunk_start or 0))
if performance_stats:
performance_stats.key = task_pack.run_result_key_to_performance_stats_key(
run_result.key)
to_put.append(performance_stats)
run_result.cost_usd = max(cost_usd, run_result.cost_usd or 0.)
run_result.modified_ts = now
result_summary = result_summary_future.get_result()
if (result_summary.try_number and
result_summary.try_number > run_result.try_number):
# The situation where a shard is retried but the bot running the previous
# try somehow reappears and reports success, the result must still show
# the last try's result. We still need to update cost_usd manually.
result_summary.costs_usd[run_result.try_number-1] = run_result.cost_usd
result_summary.modified_ts = now
else:
# Performance warning: this function calls properties_hash() which will
# GET SecretBytes entity if there's one.
result_summary.set_from_run_result(run_result, request)
to_put.append(result_summary)
ndb.put_multi(to_put)
return result_summary, run_result, None
def test_integration(self):
# Creates a TaskRequest, along its TaskResultSummary and TaskToRun. Have a
# bot reap the task, and complete the task. Ensure the resulting
# TaskResultSummary and TaskRunResult are properly updated.
request = _gen_request()
result_summary = task_result.new_result_summary(request)
to_run = task_to_run.new_task_to_run(request, 1, 0)
result_summary.modified_ts = utils.utcnow()
ndb.transaction(lambda: ndb.put_multi([result_summary, to_run]))
expected = self._gen_summary(modified_ts=self.now)
self.assertEqual(expected, result_summary.to_dict())
# Nothing changed 2 secs later except latency.
self.mock_now(self.now, 2)
self.assertEqual(expected, result_summary.to_dict())
# Task is reaped after 2 seconds (4 secs total).
reap_ts = self.now + datetime.timedelta(seconds=4)
self.mock_now(reap_ts)
to_run.queue_number = None
to_run.put()
run_result = task_result.new_run_result(request, to_run, u'localhost',
u'abc', {})
run_result.started_ts = utils.utcnow()
run_result.modified_ts = run_result.started_ts
ndb.transaction(
lambda: result_summary.set_from_run_result(run_result, request))
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = self._gen_summary(bot_dimensions={},
bot_version=u'abc',
bot_id=u'localhost',
costs_usd=[0.],
modified_ts=reap_ts,
state=task_result.State.RUNNING,
started_ts=reap_ts,
try_number=1)
self.assertEqual(expected, result_summary.key.get().to_dict())
# Task completed after 2 seconds (6 secs total), the task has been running
# for 2 seconds.
complete_ts = self.now + datetime.timedelta(seconds=6)
self.mock_now(complete_ts)
run_result.completed_ts = complete_ts
run_result.duration = 0.1
run_result.exit_code = 0
run_result.state = task_result.State.COMPLETED
run_result.modified_ts = utils.utcnow()
task_result.PerformanceStats(
key=task_pack.run_result_key_to_performance_stats_key(
run_result.key),
bot_overhead=0.1,
isolated_download=task_result.OperationStats(
duration=0.05,
initial_number_items=10,
initial_size=10000,
items_cold=large.pack([1, 2]),
items_hot=large.pack([3, 4, 5])),
isolated_upload=task_result.OperationStats(duration=0.01,
items_cold=large.pack(
[10]))).put()
ndb.transaction(
lambda: ndb.put_multi(run_result.append_output('foo', 0)))
ndb.transaction(
lambda: result_summary.set_from_run_result(run_result, request))
ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
expected = self._gen_summary(bot_dimensions={},
bot_version=u'abc',
bot_id=u'localhost',
completed_ts=complete_ts,
costs_usd=[0.],
duration=0.1,
exit_code=0,
modified_ts=complete_ts,
state=task_result.State.COMPLETED,
started_ts=reap_ts,
try_number=1)
self.assertEqual(expected, result_summary.key.get().to_dict())
expected = {
'bot_overhead': 0.1,
'isolated_download': {
'duration': 0.05,
'initial_number_items': 10,
'initial_size': 10000,
'items_cold': large.pack([1, 2]),
'items_hot': large.pack([3, 4, 5]),
'num_items_cold': 2,
'total_bytes_items_cold': 3,
'num_items_hot': 3,
'total_bytes_items_hot': 12,
},
'isolated_upload': {
'duration': 0.01,
'initial_number_items': None,
'initial_size': None,
'items_cold': large.pack([10]),
'items_hot': None,
'num_items_cold': 1,
'total_bytes_items_cold': 10,
'num_items_hot': None,
'total_bytes_items_hot': None,
},
'package_installation': {
'duration': None,
'initial_number_items': None,
'initial_size': None,
'items_cold': None,
'items_hot': None,
'num_items_cold': None,
'total_bytes_items_cold': None,
'num_items_hot': None,
'total_bytes_items_hot': None,
},
}
self.assertEqual(expected, result_summary.performance_stats.to_dict())
self.assertEqual('foo', result_summary.get_output())
self.assertEqual(datetime.timedelta(seconds=2),
result_summary.duration_as_seen_by_server)
self.assertEqual(datetime.timedelta(seconds=0.1),
result_summary.duration_now(utils.utcnow()))
self.assertEqual(datetime.timedelta(seconds=4), result_summary.pending)
self.assertEqual(datetime.timedelta(seconds=4),
result_summary.pending_now(utils.utcnow()))
self.assertEqual(task_pack.pack_result_summary_key(result_summary.key),
result_summary.task_id)
self.assertEqual(complete_ts, result_summary.ended_ts)
self.assertEqual(task_pack.pack_run_result_key(run_result.key),
run_result.task_id)
self.assertEqual(complete_ts, run_result.ended_ts)
