Bug 1310262 - Process text log artifacts in an atomic transaction (#1926

)

tests/model/derived/test_artifacts_model.py

@@ -7,7 +7,8 @@
 from treeherder.model.derived import (ArtifactsModel,
                                       JobsModel)
 from treeherder.model.models import (JobDetail,
-                                     TextLogError)
+                                     TextLogError,
+                                     TextLogStep)
 
 xfail = pytest.mark.xfail
 
@@ -124,6 +125,44 @@ def max_length(field):
     assert jd.url == long_url[:max_length("url")]
 
 
+def test_load_textlog_summary_twice(test_project, test_job):
+    text_log_summary_artifact = {
+        'type': 'json',
+        'name': 'text_log_summary',
+        'blob': json.dumps({
+            'step_data': {
+                "steps": [
+                    {
+                        'name': 'foo',
+                        'started': '2016-05-10 12:44:23.103904',
+                        'started_linenumber': 8,
+                        'finished_linenumber': 10,
+                        'finished': '2016-05-10 12:44:23.104394',
+                        'result': 'success',
+                        'errors': [
+                            {
+                                "line": '07:51:28  WARNING - foobar',
+                                "linenumber": 1587
+                            }
+                        ]
+                    }
+                ]
+            }
+        }),
+        'job_guid': test_job.guid
+    }
+
+    with ArtifactsModel(test_project) as am:
+        am.load_job_artifacts([text_log_summary_artifact])
+        assert TextLogError.objects.count() == 1
+        assert TextLogStep.objects.count() == 1
+        # load again (simulating the job being parsed twice,
+        # which sometimes happens)
+        am.load_job_artifacts([text_log_summary_artifact])
+        assert TextLogError.objects.count() == 1
+        assert TextLogStep.objects.count() == 1
+
+
 def test_load_non_ascii_textlog_errors(test_project, eleven_jobs_stored):
     with JobsModel(test_project) as jobs_model:
         job = jobs_model.get_job_list(0, 1)[0]

treeherder/model/derived/artifacts.py

@@ -3,6 +3,8 @@
 
 import dateutil.parser
 import simplejson as json
+from django.db import transaction
+from django.db.utils import IntegrityError
 from django.forms import model_to_dict
 
 from treeherder.etl.perf import load_perf_artifacts
@@ -133,36 +135,34 @@ def store_text_log_summary(self, job, text_log_summary_artifact):
         step_data = json.loads(
             text_log_summary_artifact['blob'])['step_data']
         result_map = {v: k for (k, v) in TextLogStep.RESULTS}
-        for step in step_data['steps']:
-            name = step['name'][:TextLogStep._meta.get_field('name').max_length]
-            defaults = {
-                'name': name,
-                'result': result_map[step['result']]
-            }
-            # process start/end times if we have them
-            # we currently don't support timezones in treeherder, so
-            # just ignore that when importing/updating the bug to avoid
-            # a ValueError (though by default the text log summaries
-            # we produce should have time expressed in UTC anyway)
-            for tkey in ('started', 'finished'):
-                if step.get(tkey):
-                    defaults[tkey] = dateutil.parser.parse(
-                        step[tkey], ignoretz=True)
-
-            log_step, _ = TextLogStep.objects.update_or_create(
-                job=job,
-                started_line_number=step['started_linenumber'],
-                finished_line_number=step['finished_linenumber'],
-                defaults=defaults)
-
-            if step.get('errors'):
-                for error in step['errors']:
-                    TextLogError.objects.update_or_create(
-                        step=log_step,
-                        line_number=error['linenumber'],
-                        defaults={
-                            'line': astral_filter(error['line'])
-                        })
+        with transaction.atomic():
+            for step in step_data['steps']:
+                name = step['name'][:TextLogStep._meta.get_field('name').max_length]
+                # process start/end times if we have them
+                # we currently don't support timezones in treeherder, so
+                # just ignore that when importing/updating the bug to avoid
+                # a ValueError (though by default the text log summaries
+                # we produce should have time expressed in UTC anyway)
+                time_kwargs = {}
+                for tkey in ('started', 'finished'):
+                    if step.get(tkey):
+                        time_kwargs[tkey] = dateutil.parser.parse(
+                            step[tkey], ignoretz=True)
+
+                log_step = TextLogStep.objects.create(
+                    job=job,
+                    started_line_number=step['started_linenumber'],
+                    finished_line_number=step['finished_linenumber'],
+                    name=name,
+                    result=result_map[step['result']],
+                    **time_kwargs)
+
+                if step.get('errors'):
+                    for error in step['errors']:
+                        TextLogError.objects.create(
+                            step=log_step,
+                            line_number=error['linenumber'],
+                            line=astral_filter(error['line']))
 
         # create a set of bug suggestions immediately
         load_error_summary(job.repository.name, job.id)
@@ -248,7 +248,13 @@ def load_job_artifacts(self, artifact_data):
                 elif artifact_name == 'Job Info':
                     self.store_job_details(job, artifact)
                 elif artifact_name == 'text_log_summary':
-                    self.store_text_log_summary(job, artifact)
+                    try:
+                        self.store_text_log_summary(job, artifact)
+                    except IntegrityError:
+                        logger.warning("Couldn't insert text log information "
+                                       "for job with guid %s, this probably "
+                                       "means the job was already parsed",
+                                       job_guid)
                 elif artifact_name == 'buildapi':
                     buildbot_request_id = json.loads(artifact['blob']).get(
                         'request_id')