Fix non-idempotent task that /poll reaped but returned HTTP 500.

appengine/swarming/server/task_result_test.py

 #!/usr/bin/env python
 # Copyright 2014 The LUCI Authors. All rights reserved.
 # Use of this source code is governed under the Apache License, Version 2.0
 # that can be found in the LICENSE file.
 
 import datetime
 import logging
 import os
 import random
 import sys
@@ skipping 190 matching lines @@
       'completed_ts': None,
       'cost_usd': 0.,
       'duration': None,
       'exit_code': None,
       'failure': False,
       'id': '1d69b9f088008811',
       'internal_failure': False,
       'modified_ts': None,
       'outputs_ref': None,
       'server_versions': ['v1a'],
-      'started_ts': self.now,
+      'started_ts': None,
       'state': task_result.State.RUNNING,
       'try_number': 1,
     }
     self.assertEqual(expected, actual.to_dict())
     self.assertEqual(50, actual.request.priority)
     self.assertEqual(False, actual.can_be_canceled)
 
   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
@@ skipping 42 matching lines @@
     # 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()
+    run_result.started_ts = utils.utcnow()
+    run_result.modified_ts = run_result.started_ts
     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,
@@ skipping 126 matching lines @@
         task_pack.pack_run_result_key(run_result.key),
         run_result.task_id)
     self.assertEqual(complete_ts, run_result.ended_ts)
 
   def test_yield_run_result_keys_with_dead_bot(self):
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     result_summary.modified_ts = utils.utcnow()
     ndb.transaction(result_summary.put)
     run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
-    run_result.completed_ts = utils.utcnow()
-    run_result.modified_ts = utils.utcnow()
+    run_result.started_ts = utils.utcnow()
+    run_result.completed_ts = run_result.started_ts
+    run_result.modified_ts = run_result.started_ts
     result_summary.set_from_run_result(run_result, request)
     ndb.transaction(lambda: ndb.put_multi((run_result, result_summary)))
 
     self.mock_now(self.now + task_result.BOT_PING_TOLERANCE)
     self.assertEqual(
         [], list(task_result.yield_run_result_keys_with_dead_bot()))
 
     self.mock_now(self.now + task_result.BOT_PING_TOLERANCE, 1)
     self.assertEqual(
         [run_result.key],
         list(task_result.yield_run_result_keys_with_dead_bot()))
 
   def test_set_from_run_result(self):
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
+    run_result.started_ts = utils.utcnow()
     self.assertTrue(result_summary.need_update_from_run_result(run_result))
     result_summary.modified_ts = utils.utcnow()
     run_result.modified_ts = utils.utcnow()
     ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
 
     self.assertTrue(result_summary.need_update_from_run_result(run_result))
     result_summary.set_from_run_result(run_result, request)
     ndb.transaction(lambda: ndb.put_multi([result_summary]))
 
     self.assertFalse(result_summary.need_update_from_run_result(run_result))
 
   def test_set_from_run_result_two_server_versions(self):
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
+    run_result.started_ts = utils.utcnow()
     self.assertTrue(result_summary.need_update_from_run_result(run_result))
     result_summary.modified_ts = utils.utcnow()
     run_result.modified_ts = utils.utcnow()
     ndb.transaction(lambda: ndb.put_multi((result_summary, run_result)))
 
     self.assertTrue(result_summary.need_update_from_run_result(run_result))
     result_summary.set_from_run_result(run_result, request)
     ndb.transaction(lambda: ndb.put_multi([result_summary]))
 
     run_result.signal_server_version('new-version')
     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)))
     self.assertEqual(
         ['v1a', 'new-version'], run_result.key.get().server_versions)
     self.assertEqual(
         ['v1a', 'new-version'], result_summary.key.get().server_versions)
 
   def test_set_from_run_result_two_tries(self):
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     run_result_1 = task_result.new_run_result(
         request, 1, 'localhost', 'abc', {})
+    run_result_1.started_ts = utils.utcnow()
     run_result_2 = task_result.new_run_result(
         request, 2, 'localhost', 'abc', {})
+    run_result_2.started_ts = utils.utcnow()
     self.assertTrue(result_summary.need_update_from_run_result(run_result_1))
     run_result_2.modified_ts = utils.utcnow()
     result_summary.modified_ts = utils.utcnow()
     ndb.transaction(lambda: ndb.put_multi((result_summary, run_result_2)))
 
     self.assertTrue(result_summary.need_update_from_run_result(run_result_1))
     run_result_1.modified_ts = utils.utcnow()
     result_summary.set_from_run_result(run_result_1, request)
     ndb.transaction(lambda: ndb.put_multi((result_summary, run_result_1)))
 
@@ skipping 27 matching lines @@
 
   def test_run_result_timeout(self):
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     result_summary.modified_ts = utils.utcnow()
     ndb.transaction(result_summary.put)
     run_result = task_result.new_run_result(request, 1, 'localhost', 'abc', {})
     run_result.state = task_result.State.TIMED_OUT
     run_result.duration = 0.1
     run_result.exit_code = -1
-    run_result.completed_ts = utils.utcnow()
-    run_result.modified_ts = utils.utcnow()
+    run_result.started_ts = utils.utcnow()
+    run_result.completed_ts = run_result.started_ts
+    run_result.modified_ts = run_result.started_ts
     result_summary.set_from_run_result(run_result, request)
     ndb.transaction(lambda: ndb.put_multi((run_result, result_summary)))
     run_result = run_result.key.get()
     result_summary = result_summary.key.get()
     self.assertEqual(True, run_result.failure)
     self.assertEqual(True, result_summary.failure)
 
   def test_performance_stats_pre_put_hook(self):
     with self.assertRaises(datastore_errors.BadValueError):
       task_result.PerformanceStats().put()
 
   def test_get_result_summaries_query(self):
     # Indirectly tested by API.
     pass
 
   def test_get_run_results_query(self):
     # Indirectly tested by API.
     pass
 
 
 class TestOutput(TestCase):
   def setUp(self):
     super(TestOutput, self).setUp()
     request = mkreq(_gen_request())
     result_summary = task_result.new_result_summary(request)
     result_summary.modified_ts = utils.utcnow()
     ndb.transaction(result_summary.put)
     self.run_result = task_result.new_run_result(
         request, 1, 'localhost', 'abc', {})
+    self.run_result.started_ts = result_summary.modified_ts
     self.run_result.modified_ts = utils.utcnow()
     result_summary.set_from_run_result(self.run_result, request)
     ndb.transaction(lambda: ndb.put_multi((result_summary, self.run_result)))
     self.run_result = self.run_result.key.get()
 
   def assertTaskOutputChunk(self, expected):
     q = task_result.TaskOutputChunk.query().order(
         task_result.TaskOutputChunk.key)
     self.assertEqual(expected, [t.to_dict() for t in q.fetch()])
 
@@ skipping 126 matching lines @@
         task_result.TaskOutput.CHUNK_SIZE * '\x00' + 'Baz\x00Bar\x00FooWow',
         self.run_result.get_output())
     self.assertTaskOutputChunk(
         [{'chunk': 'Baz\x00Bar\x00FooWow', 'gaps': [3, 4, 7, 8]}])
 
 
 if __name__ == '__main__':
   if '-v' in sys.argv:
     unittest.TestCase.maxDiff = None
   unittest.main()